Feb 26 22:50:00 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:00 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:00 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:00 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:00 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:05 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:05 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:05 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:05 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:05 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:08 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:08 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:08 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:08 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:08 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:08 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25212 Feb 26 22:50:08 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:09 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:09 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:09 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:09 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:09 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:09 wm-audio volumio[2491]: info: [1772142609228] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:09 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:09 wm-audio volumio[2491]: info: sendMpdCommand stop took 4 milliseconds Feb 26 22:50:09 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:09 wm-audio volumio[2491]: info: Feb 26 22:50:09 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:09 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:09 wm-audio volumio[2491]: info: sendMpdCommand clear took 1 milliseconds Feb 26 22:50:09 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:10 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:10 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:10 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25212 Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:10 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:10 wm-audio volumio[2491]: info: [1772142610370] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:10 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:10 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:10 wm-audio volumio[2491]: info: ------------------------------ 1480ms Feb 26 22:50:10 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:10 wm-audio volumio[2491]: info: sendMpdCommand stop took 342 milliseconds Feb 26 22:50:10 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:10 wm-audio volumio[2491]: info: Feb 26 22:50:10 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:10 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:10 wm-audio volumio[2491]: info: Feb 26 22:50:10 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:10 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:10 wm-audio volumio[2491]: info: sendMpdCommand add "https://icestreaming.rai.it/1.mp3" took 20 milliseconds Feb 26 22:50:10 wm-audio volumio[2491]: info: sendMpdCommand clear took 19 milliseconds Feb 26 22:50:10 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:10 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:10 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:10 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:10 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:10 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:10 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:10 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:11 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:11 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:11 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s67001 Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:11 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:11 wm-audio volumio[2491]: info: [1772142611548] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:11 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:11 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:11 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:11 wm-audio volumio[2491]: info: ------------------------------ 819ms Feb 26 22:50:11 wm-audio volumio[2491]: info: ------------------------------ 818ms Feb 26 22:50:11 wm-audio volumio[2491]: info: sendMpdCommand play took 817 milliseconds Feb 26 22:50:11 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:11 wm-audio volumio[2491]: info: sendMpdCommand stop took 3 milliseconds Feb 26 22:50:11 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:11 wm-audio volumio[2491]: info: Feb 26 22:50:11 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:11 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:11 wm-audio volumio[2491]: info: Feb 26 22:50:11 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:11 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:11 wm-audio volumio[2491]: info: sendMpdCommand add "https://icestreaming.rai.it/1.mp3" took 7 milliseconds Feb 26 22:50:11 wm-audio volumio[2491]: info: sendMpdCommand clear took 7 milliseconds Feb 26 22:50:11 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:11 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:11 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "http://radiobzlive.rai.it/RAIBZ_Livestream" Feb 26 22:50:12 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:12 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 506ms Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 506ms Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand play took 503 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "http://radiobzlive.rai.it/RAIBZ_Livestream" Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:12 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand add "http://radiobzlive.rai.it/RAIBZ_Livestream" took 4 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 5ms Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand play took 3 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand status took 7 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand status took 4 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RAIBZ_Livestream","artist":null,"album":null,"uri":"http://radiobzlive.rai.it/RAIBZ_Livestream","trackType":""} Feb 26 22:50:12 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 22ms Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"RAIBZ_Livestream","artist":null,"album":null,"uri":"http://radiobzlive.rai.it/RAIBZ_Livestream","trackType":""} Feb 26 22:50:12 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:12 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.440+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.442+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.443+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://radiobzlive.rai.it/RAIBZ_Livestream title="Rai Südtirol" Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.445+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://radiobzlive.rai.it/RAIBZ_Livestream title="Rai Südtirol" Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 51ms Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:12 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 2ms Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1397,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"RAIBZ_Livestream","artist":"RAI Suedtirol","album":null,"uri":"http://radiobzlive.rai.it/RAIBZ_Livestream","trackType":""} Feb 26 22:50:12 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:12 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.495+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.496+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.498+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://radiobzlive.rai.it/RAIBZ_Livestream title="Rai Südtirol" Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.499+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://radiobzlive.rai.it/RAIBZ_Livestream title="Rai Südtirol" Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 37ms Feb 26 22:50:12 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:50:12 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:50:12 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::stPlaybackTimer Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::serviceStop Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::serviceStop Feb 26 22:50:12 wm-audio volumio[2491]: info: [1772142612777] ControllerWebradio::stop Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:12 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:12 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s252802 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.790+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.791+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://radiobzlive.rai.it/RAIBZ_Livestream title="Rai Südtirol" Feb 26 22:50:12 wm-audio volumio[2491]: info: Feb 26 22:50:12 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand stop took 37 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:12 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:12 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: 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":"RAIBZ_Livestream","artist":"RAI Suedtirol","album":null,"uri":"http://radiobzlive.rai.it/RAIBZ_Livestream","trackType":""} Feb 26 22:50:12 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService stop Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio[2491]: info: No code Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:12 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:12 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.842+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.842+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.844+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.844+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.846+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:12 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:12.846+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:12 wm-audio volumio[2491]: info: ------------------------------ 44ms Feb 26 22:50:12 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: [1772142613071] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand stop took 5 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:13 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand clear took 2 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "http://icestreaming.rai.it/12.mp3" Feb 26 22:50:13 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 2ms Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "http://icestreaming.rai.it/12.mp3" Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand add "http://icestreaming.rai.it/12.mp3" took 1 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:13 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand play took 3 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 2ms Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand status took 8 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"12.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/12.mp3","trackType":"mp3"} Feb 26 22:50:13 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 16ms Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"12.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/12.mp3","trackType":"mp3"} Feb 26 22:50:13 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:13 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.396+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.396+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/12.mp3 title="RAI Isoradio Estero" Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.397+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.397+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/12.mp3 title="RAI Isoradio Estero" Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 42ms Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:13 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:13 wm-audio volumio[2491]: info: Feb 26 22:50:13 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 11ms Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand status took 10 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:13 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:50:13 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:13 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"12.mp3","artist":"Isoradio Estero","album":null,"uri":"http://icestreaming.rai.it/12.mp3","trackType":"mp3"} Feb 26 22:50:13 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:13 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:13 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.439+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.440+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/12.mp3 title="RAI Isoradio Estero" Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.441+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:13 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:13.442+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/12.mp3 title="RAI Isoradio Estero" Feb 26 22:50:13 wm-audio volumio[2491]: info: ------------------------------ 42ms Feb 26 22:50:13 wm-audio volumio[2491]: info: camilladsp respawn in 800 ms (attempt 4/10) Feb 26 22:50:13 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:50:13 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:50:13 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:50:13 wm-audio volumio[2491]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 26 22:50:15 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:15 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:15 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:15 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:15 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:17 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::stPlaybackTimer Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::serviceStop Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::serviceStop Feb 26 22:50:17 wm-audio volumio[2491]: info: [1772142617354] ControllerWebradio::stop Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:17 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:17 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25212 Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:17 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:17.362+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:17 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:17.363+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/12.mp3 title="RAI Isoradio Estero" Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:17 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:17 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:17 wm-audio volumio[2491]: info: [1772142617388] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:17 wm-audio volumio[2491]: info: Feb 26 22:50:17 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:17 wm-audio volumio[2491]: info: sendMpdCommand stop took 45 milliseconds Feb 26 22:50:17 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:17 wm-audio volumio[2491]: info: sendMpdCommand stop took 11 milliseconds Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:17 wm-audio volumio[2491]: info: Feb 26 22:50:17 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:17 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:17 wm-audio volumio[2491]: info: sendMpdCommand status took 9 milliseconds Feb 26 22:50:17 wm-audio volumio[2491]: info: sendMpdCommand clear took 9 milliseconds Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:17 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:17 wm-audio volumio[2491]: info: ------------------------------ 9ms Feb 26 22:50:17 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 26 22:50:17 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:17 wm-audio volumio[2491]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 26 22:50:17 wm-audio volumio[2491]: info: ------------------------------ 21ms Feb 26 22:50:18 wm-audio volumio[2491]: info: camilladsp respawn in 1600 ms (attempt 5/10) Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "https://icestreaming.rai.it/1.mp3" Feb 26 22:50:18 wm-audio volumio[2491]: info: Feb 26 22:50:18 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:18 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand add "https://icestreaming.rai.it/1.mp3" took 2 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:18 wm-audio volumio[2491]: info: ------------------------------ 4ms Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand play took 4 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: info: Feb 26 22:50:18 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:18 wm-audio volumio[2491]: info: Feb 26 22:50:18 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand status took 4 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand status took 3 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:18 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1.mp3","artist":null,"album":null,"uri":"https://icestreaming.rai.it/1.mp3","trackType":"mp3"} Feb 26 22:50:18 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:18 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1.mp3","artist":null,"album":null,"uri":"https://icestreaming.rai.it/1.mp3","trackType":"mp3"} Feb 26 22:50:18 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:18 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:18 wm-audio volumio[2491]: info: ------------------------------ 24ms Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.900+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.901+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=https://icestreaming.rai.it/1.mp3 title="RAI Radio 1" Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.902+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.902+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=https://icestreaming.rai.it/1.mp3 title="RAI Radio 1" Feb 26 22:50:18 wm-audio volumio[2491]: info: ------------------------------ 38ms Feb 26 22:50:18 wm-audio volumio[2491]: info: Feb 26 22:50:18 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:18 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:18 wm-audio volumio[2491]: info: Feb 26 22:50:18 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:18 wm-audio volumio[2491]: info: ------------------------------ 12ms Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand status took 11 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:18 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 22:50:18 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:18 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:18 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"1.mp3","artist":"Radio1","album":null,"uri":"https://icestreaming.rai.it/1.mp3","trackType":"mp3"} Feb 26 22:50:18 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:18 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:18 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.955+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=80 volume=55 Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.956+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=https://icestreaming.rai.it/1.mp3 title="RAI Radio 1" Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.956+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=80 volume=55 Feb 26 22:50:18 wm-audio volumio[2491]: info: ------------------------------ 47ms Feb 26 22:50:18 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:18.967+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=https://icestreaming.rai.it/1.mp3 title="RAI Radio 1" Feb 26 22:50:19 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:50:19 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:50:19 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:50:19 wm-audio volumio[2491]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 26 22:50:21 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:21 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:21 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:21 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:21 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:26 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:26 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:26 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:26 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:26 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:31 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:31 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:31 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:31 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:31 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:36 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:36 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:36 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:36 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:36 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:41 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:41 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:41 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:41 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:41 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:44 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::stPlaybackTimer Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::serviceStop Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::serviceStop Feb 26 22:50:44 wm-audio volumio[2491]: info: [1772142644746] ControllerWebradio::stop Feb 26 22:50:44 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:44 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:44 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25592 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.762+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.763+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=https://icestreaming.rai.it/1.mp3 title="RAI Radio 1" Feb 26 22:50:44 wm-audio volumio[2491]: info: Feb 26 22:50:44 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:44 wm-audio volumio[2491]: info: sendMpdCommand stop took 66 milliseconds Feb 26 22:50:44 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:44 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:44 wm-audio volumio[2491]: info: sendMpdCommand status took 5 milliseconds Feb 26 22:50:44 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:44 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:44 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 26 22:50:44 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:44 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: 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":"1.mp3","artist":"Radio1","album":null,"uri":"https://icestreaming.rai.it/1.mp3","trackType":"mp3"} Feb 26 22:50:44 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService stop Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:44 wm-audio volumio[2491]: info: No code Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:44 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:44 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.849+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.849+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.851+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.852+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.854+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:44 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:44.854+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:44 wm-audio volumio[2491]: info: ------------------------------ 61ms Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: [1772142645338] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand stop took 5 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:45 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand clear took 3 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "http://icestreaming.rai.it/4.mp3" Feb 26 22:50:45 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 4ms Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "http://icestreaming.rai.it/4.mp3" Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:45 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand add "http://icestreaming.rai.it/4.mp3" took 1 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 2ms Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand play took 2 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:45 wm-audio volumio[2491]: info: camilladsp respawn in 3200 ms (attempt 6/10) Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand status took 8 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/4.mp3","trackType":"mp3"} Feb 26 22:50:45 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 13ms Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/4.mp3","trackType":"mp3"} Feb 26 22:50:45 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:45 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.637+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.637+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/4.mp3 title="Rai Radio Tutta Italiana" Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.639+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.639+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/4.mp3 title="Rai Radio Tutta Italiana" Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 38ms Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:45 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:45 wm-audio volumio[2491]: info: Feb 26 22:50:45 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 3ms Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:45 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:50:45 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:45 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"4.mp3","artist":"Radio Tutta ITA","album":null,"uri":"http://icestreaming.rai.it/4.mp3","trackType":"mp3"} Feb 26 22:50:45 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:45 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:45 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.706+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.707+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/4.mp3 title="Rai Radio Tutta Italiana" Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.709+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:45 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:45.710+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/4.mp3 title="Rai Radio Tutta Italiana" Feb 26 22:50:45 wm-audio volumio[2491]: info: ------------------------------ 35ms Feb 26 22:50:45 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:50:45 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:50:46 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:50:46 wm-audio volumio[2491]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 26 22:50:47 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:47 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:47 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:47 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:47 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:51 wm-audio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 26 22:50:52 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:52 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:52 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:52 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:52 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:57 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:57 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:57 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:50:57 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:50:57 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:50:58 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::stPlaybackTimer Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::serviceStop Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::serviceStop Feb 26 22:50:58 wm-audio volumio[2491]: info: [1772142658060] ControllerWebradio::stop Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:50:58 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:50:58 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s132646 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.076+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.076+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/4.mp3 title="Rai Radio Tutta Italiana" Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand stop took 64 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand status took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: 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":"4.mp3","artist":"Radio Tutta ITA","album":null,"uri":"http://icestreaming.rai.it/4.mp3","trackType":"mp3"} Feb 26 22:50:58 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService stop Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio[2491]: info: No code Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.156+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.157+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.159+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.160+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.161+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.162+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 58ms Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: [1772142658525] ControllerWebradio::clearAddPlayTrack Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand stop took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:58 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand clear took 1 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "http://icestreaming.rai.it/11.mp3" Feb 26 22:50:58 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 3ms Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "http://icestreaming.rai.it/11.mp3" Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand add "http://icestreaming.rai.it/11.mp3" took 0 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:58 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand play took 2 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 7ms Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand status took 9 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand status took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/11.mp3","trackType":"mp3"} Feb 26 22:50:58 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 15ms Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/11.mp3","trackType":"mp3"} Feb 26 22:50:58 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:58 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.784+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.784+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/11.mp3 title="Rai Radio Kids" Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.786+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.786+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/11.mp3 title="Rai Radio Kids" Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 35ms Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:50:58 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:50:58 wm-audio volumio[2491]: info: Feb 26 22:50:58 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 3ms Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand status took 3 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:50:58 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:50:58 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"11.mp3","artist":"Radio Kids","album":null,"uri":"http://icestreaming.rai.it/11.mp3","trackType":"mp3"} Feb 26 22:50:58 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:50:58 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:50:58 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.836+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=270 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.836+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/11.mp3 title="Rai Radio Kids" Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.838+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=270 volume=55 Feb 26 22:50:58 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:50:58.839+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/11.mp3 title="Rai Radio Kids" Feb 26 22:50:58 wm-audio volumio[2491]: info: ------------------------------ 40ms Feb 26 22:50:58 wm-audio volumio[2491]: info: camilladsp respawn in 6400 ms (attempt 7/10) Feb 26 22:50:58 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:50:58 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:50:59 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:50:59 wm-audio volumio[2491]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 26 22:51:02 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:02 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:02 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:02 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:02 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:02 wm-audio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 26 22:51:02 wm-audio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 26 22:51:02 wm-audio systemd[1]: setdatetime-helper.service: Consumed 1.140s CPU time. Feb 26 22:51:07 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:07 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:07 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:07 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:07 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:13 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:13 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:13 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:13 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:13 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:18 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:18 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:18 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:18 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:18 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:19 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::ClearQueue Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::stPlaybackTimer Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::serviceStop Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::serviceStop Feb 26 22:51:19 wm-audio volumio[2491]: info: [1772142679607] ControllerWebradio::stop Feb 26 22:51:19 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::clearPlayQueue Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::addQueueItems Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::addQueueItems Feb 26 22:51:19 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:51:19 wm-audio volumio[2491]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s25211 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.614+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.615+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/11.mp3 title="Rai Radio Kids" Feb 26 22:51:19 wm-audio volumio[2491]: info: Feb 26 22:51:19 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:51:19 wm-audio volumio[2491]: info: sendMpdCommand stop took 54 milliseconds Feb 26 22:51:19 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:51:19 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:51:19 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:51:19 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:51:19 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:51:19 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 22:51:19 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:51:19 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: 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":"11.mp3","artist":"Radio Kids","album":null,"uri":"http://icestreaming.rai.it/11.mp3","trackType":"mp3"} Feb 26 22:51:19 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService stop Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:19 wm-audio volumio[2491]: info: No code Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:19 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:19 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.688+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.689+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.690+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.691+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.692+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_STOPPED positionMs=0 volume=55 Feb 26 22:51:19 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:19.693+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id= title= Feb 26 22:51:19 wm-audio volumio[2491]: info: ------------------------------ 49ms Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushQueue Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::saveQueue Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::updateTrackBlock Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrackBlock Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPlay Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::play index 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::stop Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::play index undefined Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::startPlaybackTimer Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: [1772142680049] ControllerWebradio::clearAddPlayTrack Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand stop took 4 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:51:20 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand clear took 2 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand load "http://icestreaming.rai.it/3.mp3" Feb 26 22:51:20 wm-audio volumio[2491]: error: updateQueue error: null Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 5ms Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand add "http://icestreaming.rai.it/3.mp3" Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:51:20 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand add "http://icestreaming.rai.it/3.mp3" took 3 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand play Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 4ms Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand play took 4 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand status took 8 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/3.mp3","trackType":"mp3"} Feb 26 22:51:20 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus stop Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 16ms Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3.mp3","artist":null,"album":null,"uri":"http://icestreaming.rai.it/3.mp3","trackType":"mp3"} Feb 26 22:51:20 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:51:20 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.380+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.380+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/3.mp3 title="RAI Radio 3" Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.384+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.385+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/3.mp3 title="RAI Radio 3" Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 45ms Feb 26 22:51:20 wm-audio volumio[2491]: info: camilladsp respawn in 10000 ms (attempt 8/10) Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces system playlist update Feb 26 22:51:20 wm-audio volumio[2491]: info: Ignoring MPD Status Update Feb 26 22:51:20 wm-audio volumio[2491]: info: Feb 26 22:51:20 wm-audio volumio[2491]: ---------------------------- MPD announces state update: player Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::getState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand status Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 3ms Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand status took 2 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseState Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 22:51:20 wm-audio volumio[2491]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 22:51:20 wm-audio volumio[2491]: verbose: ControllerMpd::parseTrackInfo Feb 26 22:51:20 wm-audio volumio[2491]: info: ControllerMpd::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::servicePushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"3.mp3","artist":"Radio3","album":null,"uri":"http://icestreaming.rai.it/3.mp3","trackType":"mp3"} Feb 26 22:51:20 wm-audio volumio[2491]: verbose: CURRENT POSITION 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState stateService play Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::syncState currentStatus play Feb 26 22:51:20 wm-audio volumio[2491]: info: Received an update from plugin. extracting info from payload Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CorePlayQueue::getTrack 0 Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreStateMachine::pushState Feb 26 22:51:20 wm-audio volumio[2491]: info: CoreCommandRouter::volumioPushState Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.432+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.433+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/3.mp3 title="RAI Radio 3" Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.435+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" state=STATUS_PLAYING positionMs=0 volume=55 Feb 26 22:51:20 wm-audio volumio5-onboarding[1799]: time=2026-02-26T22:51:20.436+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.7:41796 @ 0x2400e40" id=http://icestreaming.rai.it/3.mp3 title="RAI Radio 3" Feb 26 22:51:20 wm-audio volumio[2491]: info: ------------------------------ 44ms Feb 26 22:51:20 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 22:51:20 wm-audio volumio[2491]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 22:51:20 wm-audio volumio[2491]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 22:51:20 wm-audio volumio[2491]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 26 22:51:23 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:23 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:23 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:23 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:23 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:26 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 26 22:51:26 wm-audio volumio[2491]: info: UPNP Browser: No servers found, reinitializing and searching... Feb 26 22:51:28 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:28 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:28 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:28 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:28 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:29 wm-audio volumio[2491]: info: UPNP Browser: Returning 0 server(s) after 3s wait Feb 26 22:51:29 wm-audio volumio[2491]: info: Preload queue cleared Feb 26 22:51:33 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:33 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:33 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:33 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:33 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:39 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:39 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:39 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:39 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:39 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:44 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:44 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:44 wm-audio volumio[2491]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Feb 26 22:51:44 wm-audio volumio[2491]: info: Discovery: Restarting Browsing Feb 26 22:51:44 wm-audio volumio[2491]: info: Discovery: Restart already pending, ignoring duplicate call Feb 26 22:51:45 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:45 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:45 wm-audio volumio[2491]: info: Retrieving Cloud Streaming UI Feb 26 22:51:45 wm-audio volumio[2491]: info: Getting Tidal Cloud Configuration Feb 26 22:51:45 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:45 wm-audio volumio[2491]: info: Getting Qobuz Cloud Configuration Feb 26 22:51:45 wm-audio volumio[2491]: info: Asking plugin for UI Config Feb 26 22:51:45 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:45 wm-audio volumio[2491]: info: Getting Spotify Cloud Configuration Feb 26 22:51:46 wm-audio volumio[2491]: info: Asking plugin for UI Config Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:46 wm-audio volumio[2491]: info: Saving Spotify Acccount Feb 26 22:51:46 wm-audio volumio[2491]: info: Got Tidal Cloud Configuration Feb 26 22:51:46 wm-audio volumio[2491]: info: Got it Feb 26 22:51:46 wm-audio volumio[2491]: info: Got it Feb 26 22:51:46 wm-audio volumio[2491]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 26 22:51:46 wm-audio volumio[2491]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::volumioGetBrowseSources Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 26 22:51:46 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 26 22:51:47 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Feb 26 22:51:47 wm-audio volumio[2491]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Feb 26 22:51:48 wm-audio volumio[2491]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:51:48 wm-audio volumio[2491]: Error: getaddrinfo -3007 Feb 26 22:51:48 wm-audio volumio[2491]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Feb 26 22:51:48 wm-audio volumio[2491]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Feb 26 22:51:48 wm-audio volumio[2491]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Feb 26 22:51:48 wm-audio volumio[2491]: code: -3007, Feb 26 22:51:48 wm-audio volumio[2491]: errno: -3007, Feb 26 22:51:48 wm-audio volumio[2491]: syscall: 'getaddrinfo' Feb 26 22:51:48 wm-audio volumio[2491]: } Feb 26 22:51:48 wm-audio volumio[2491]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 22:51:48 wm-audio sudo[5118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 22:50' Feb 26 22:51:48 wm-audio sudo[5118]: 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"