Oct 13 19:23:00 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:00 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:04 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:04 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/location Oct 13 19:23:04 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:05 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:05 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/browse/?id=r101217 Oct 13 19:23:05 harmonmiller volumio[1160]: info: [TuneIn] Fetching (browse) results For tunein/browse/?id=r101217 Oct 13 19:23:06 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:06 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 19:23:10 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:10 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/browse/?id=r101286 Oct 13 19:23:10 harmonmiller volumio[1160]: info: [TuneIn] Fetching (browse) results For tunein/browse/?id=r101286 Oct 13 19:23:10 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:10 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:14 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:14 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/browse/?id=r101286&pivot=name&filter=country Oct 13 19:23:14 harmonmiller volumio[1160]: info: [TuneIn] Fetching (browse) results For tunein/browse/?id=r101286&pivot=name&filter=country Oct 13 19:23:14 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 19:23:15 harmonmiller volumio[1160]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 13 19:23:15 harmonmiller volumio[1160]: info: Received Get System Version Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 19:23:15 harmonmiller volumio[1160]: info: Received Get System Info Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 19:23:15 harmonmiller volumio[1160]: info: Discovery: Getting this device information Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 19:23:15 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:23:15 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/browse/?id=r101286&filter=s:~C:country Oct 13 19:23:15 harmonmiller volumio[1160]: info: [TuneIn] Fetching (browse) results For tunein/browse/?id=r101286&filter=s:~C:country Oct 13 19:23:16 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:17 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::serviceStop Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::serviceStop Oct 13 19:23:17 harmonmiller volumio[1160]: info: [yt-cast-receiver] Player.stop() Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:23:17 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:17 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s137149&filter=s:~C:country Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:23:17 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:17 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:17 harmonmiller volumio[1160]: info: sendMpdCommand status took 5 milliseconds Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:17 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.607+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PAUSED positionMs=985 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.607+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PAUSED positionMs=985 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.609+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title="PROFANATICA | Paul Ledney: Black Metal, Religion, GG Allin & Afterlife | Garza Podcast 189" Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.610+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title="PROFANATICA | Paul Ledney: Black Metal, Religion, GG Allin & Afterlife | Garza Podcast 189" Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: UNSET VOLATILE: Service: ytcr Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.886+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PAUSED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.886+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PAUSED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.887+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title= Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.887+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title= Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.890+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PAUSED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.890+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PAUSED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.891+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title= Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.891+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title= Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::stPlaybackTimer Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::serviceStop Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreCommandRouter::serviceStop Oct 13 19:23:17 harmonmiller volumio[1160]: info: [1791915797904] ControllerWebradio::stop Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.913+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.913+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=70 Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.914+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=https://play.radioregional.pt:8220/stream/2/ title="Cascais FM - 105.4" Oct 13 19:23:17 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:17.914+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=https://play.radioregional.pt:8220/stream/2/ title="Cascais FM - 105.4" Oct 13 19:23:17 harmonmiller volumio[1160]: info: sendMpdCommand stop took 52 milliseconds Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:17 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:23:17 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:17 harmonmiller volumio[1160]: info: [1791915797961] ControllerWebradio::clearAddPlayTrack Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:17 harmonmiller volumio[1160]: info: sendMpdCommand stop took 1 milliseconds Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:23:17 harmonmiller volumio[1160]: info: Oct 13 19:23:17 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:17 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:17 harmonmiller volumio[1160]: info: sendMpdCommand clear took 6 milliseconds Oct 13 19:23:17 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:23:18 harmonmiller volumio[1160]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 13 19:23:18 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:23:18 harmonmiller volumio[1160]: info: ------------------------------ 586ms Oct 13 19:23:18 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:23:18 harmonmiller volumio[1160]: info: Oct 13 19:23:18 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:18 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:18 harmonmiller volumio[1160]: info: sendMpdCommand add "https://play.radioregional.pt:8220/stream/2/" took 2 milliseconds Oct 13 19:23:18 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 19:23:18 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand play Oct 13 19:23:18 harmonmiller volumio[1160]: info: ------------------------------ 4ms Oct 13 19:23:18 harmonmiller volumio[1160]: info: sendMpdCommand play took 3 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:19 harmonmiller volumio[1160]: info: Oct 13 19:23:19 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:19 harmonmiller volumio[1160]: info: Oct 13 19:23:19 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:19 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand status took 14 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand status took 15 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:19 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand status took 34 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand status took 35 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 25 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 24 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:19 harmonmiller volumio[1160]: 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":"","artist":null,"album":null,"uri":"https://play.radioregional.pt:8220/stream/2/","trackType":""} Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: No code Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.197+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.197+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.199+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.200+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.200+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.200+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.201+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.202+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.203+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.203+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1002 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.204+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.205+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio[1160]: info: ------------------------------ 97ms Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 90 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 88 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 81 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 80 milliseconds Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:19 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:19 harmonmiller volumio[1160]: 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":"","artist":null,"album":null,"uri":"https://play.radioregional.pt:8220/stream/2/","trackType":""} Oct 13 19:23:19 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: No code Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:19 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.283+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.284+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.284+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.285+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.286+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.286+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.288+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.289+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1285 volume=70 Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.289+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.289+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.289+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:19.289+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:19 harmonmiller volumio[1160]: info: ------------------------------ 178ms Oct 13 19:23:23 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:23:23 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:23 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s339797&filter=s:~C:country Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:23 harmonmiller volumio[1160]: info: [1791915803451] ControllerWebradio::clearAddPlayTrack Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand stop took 7 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:23:23 harmonmiller volumio[1160]: info: Oct 13 19:23:23 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:23 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand clear took 2 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "https://a1.asurahosting.com:9320/radio.mp3" Oct 13 19:23:23 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:23:23 harmonmiller volumio[1160]: info: ------------------------------ 7ms Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "https://a1.asurahosting.com:9320/radio.mp3" Oct 13 19:23:23 harmonmiller volumio[1160]: info: Oct 13 19:23:23 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:23 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand add "https://a1.asurahosting.com:9320/radio.mp3" took 2 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand play Oct 13 19:23:23 harmonmiller volumio[1160]: info: ------------------------------ 5ms Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand play took 9 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:23 harmonmiller volumio[1160]: info: Oct 13 19:23:23 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:23 harmonmiller volumio[1160]: info: Oct 13 19:23:23 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:23 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://a1.asurahosting.com:9320/radio.mp3"; Failed to connect to a1.asurahosting.com port 9320 after 73 ms: Couldn't connect to server: Couldn't connect to server Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand status took 20 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://a1.asurahosting.com:9320/radio.mp3"; Failed to connect to a1.asurahosting.com port 9320 after 73 ms: Couldn't connect to server: Couldn't connect to server Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand status took 20 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:23 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://a1.asurahosting.com:9320/radio.mp3"; Failed to connect to a1.asurahosting.com port 9320 after 73 ms: Couldn't connect to server: Couldn't connect to server Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand status took 37 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://a1.asurahosting.com:9320/radio.mp3"; Failed to connect to a1.asurahosting.com port 9320 after 73 ms: Couldn't connect to server: Couldn't connect to server Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand status took 38 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 30 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 28 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:23 harmonmiller volumio[1160]: 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":"radio.mp3","artist":null,"album":null,"uri":"https://a1.asurahosting.com:9320/radio.mp3","trackType":"mp3"} Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: No code Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.736+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.736+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.739+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.739+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.741+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.741+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.742+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.742+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.743+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.744+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=49 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.744+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.745+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio[1160]: info: ------------------------------ 116ms Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 104 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 103 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 89 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 88 milliseconds Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:23 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:23 harmonmiller volumio[1160]: 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":"radio.mp3","artist":null,"album":null,"uri":"https://a1.asurahosting.com:9320/radio.mp3","trackType":"mp3"} Oct 13 19:23:23 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: No code Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:23 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.833+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.833+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.834+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.834+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.836+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.837+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.837+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.838+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.841+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.841+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=337 volume=70 Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.842+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:23.842+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:23 harmonmiller volumio[1160]: info: ------------------------------ 203ms Oct 13 19:23:25 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:23:25 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:25 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s137149&filter=s:~C:country Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:25 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:23:25 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:25 harmonmiller volumio[1160]: info: [1791915805744] ControllerWebradio::clearAddPlayTrack Oct 13 19:23:25 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:25 harmonmiller volumio[1160]: info: sendMpdCommand stop took 8 milliseconds Oct 13 19:23:25 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:23:25 harmonmiller volumio[1160]: info: Oct 13 19:23:25 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:25 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:25 harmonmiller volumio[1160]: info: sendMpdCommand clear took 2 milliseconds Oct 13 19:23:25 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:23:25 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:23:25 harmonmiller volumio[1160]: info: ------------------------------ 2ms Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:23:26 harmonmiller volumio[1160]: info: Oct 13 19:23:26 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:26 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand add "https://play.radioregional.pt:8220/stream/2/" took 2 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand play Oct 13 19:23:26 harmonmiller volumio[1160]: info: ------------------------------ 4ms Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand play took 3 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:26 harmonmiller volumio[1160]: info: Oct 13 19:23:26 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:26 harmonmiller volumio[1160]: info: Oct 13 19:23:26 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:26 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand status took 11 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand status took 13 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:26 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand status took 26 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: error: MPD returned error for command status: Failed to decode "https://play.radioregional.pt:8220/stream/2/"; server certificate verification failed. CAfile: none CRLfile: none: SSL peer certificate or SSH remote key was not OK Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand status took 26 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 20 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 18 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:26 harmonmiller volumio[1160]: 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":"","artist":null,"album":null,"uri":"https://play.radioregional.pt:8220/stream/2/","trackType":""} Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: No code Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.839+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.840+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.841+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.841+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.842+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.842+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.843+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.843+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.843+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.844+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.846+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.847+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio[1160]: info: ------------------------------ 82ms Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 76 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand clearerror took 76 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 69 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:26 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:26 harmonmiller volumio[1160]: 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":"","artist":null,"album":null,"uri":"https://play.radioregional.pt:8220/stream/2/","trackType":""} Oct 13 19:23:26 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: No code Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:26 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.906+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.906+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.907+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.907+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.908+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.908+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.909+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.909+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.911+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.911+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=1049 volume=70 Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.912+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:26.912+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="jellyfin/theboard@86966bf557dd40cbaf3e6f35acbf2c49/song@songId=3041c1f59ca21a6c3da5064e23b08c39" title="Cosmic Underground" Oct 13 19:23:26 harmonmiller volumio[1160]: info: ------------------------------ 145ms Oct 13 19:23:27 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:23:27 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:27 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s342198&filter=s:~C:country Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:27 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:23:27 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:27 harmonmiller volumio[1160]: info: [1791915807994] ControllerWebradio::clearAddPlayTrack Oct 13 19:23:27 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:27 harmonmiller volumio[1160]: info: sendMpdCommand stop took 4 milliseconds Oct 13 19:23:27 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:23:27 harmonmiller volumio[1160]: info: Oct 13 19:23:27 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:28 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:28 harmonmiller volumio[1160]: info: sendMpdCommand clear took 2 milliseconds Oct 13 19:23:28 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "https://online.classicrock.pt/stream1?type=http" Oct 13 19:23:28 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:23:28 harmonmiller volumio[1160]: info: ------------------------------ 3ms Oct 13 19:23:28 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "https://online.classicrock.pt/stream1?type=http" Oct 13 19:23:28 harmonmiller volumio[1160]: info: Oct 13 19:23:28 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:28 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:28 harmonmiller volumio[1160]: info: sendMpdCommand add "https://online.classicrock.pt/stream1?type=http" took 2 milliseconds Oct 13 19:23:28 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 19:23:28 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand play Oct 13 19:23:28 harmonmiller volumio[1160]: info: ------------------------------ 4ms Oct 13 19:23:28 harmonmiller volumio[1160]: info: sendMpdCommand play took 3 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: info: Oct 13 19:23:29 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: info: Oct 13 19:23:29 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 7 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 7 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 6 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 3 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:29 harmonmiller volumio[1160]: 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":"stream1?type=http","artist":null,"album":null,"uri":"https://online.classicrock.pt/stream1?type=http","trackType":""} Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:29 harmonmiller volumio[1160]: info: ------------------------------ 17ms Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:29 harmonmiller volumio[1160]: 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":"stream1?type=http","artist":null,"album":null,"uri":"https://online.classicrock.pt/stream1?type=http","trackType":""} Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus play Oct 13 19:23:29 harmonmiller volumio[1160]: info: Received an update from plugin. extracting info from payload Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.321+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.321+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.323+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.324+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.324+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.325+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.324+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.325+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio[1160]: info: ------------------------------ 48ms Oct 13 19:23:29 harmonmiller volumio[1160]: info: Oct 13 19:23:29 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:29 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: info: Oct 13 19:23:29 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 5 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: ------------------------------ 7ms Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand status took 4 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"stream1?type=http","artist":"Classic Rock Portugal","album":null,"uri":"https://online.classicrock.pt/stream1?type=http","trackType":""} Oct 13 19:23:29 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus play Oct 13 19:23:29 harmonmiller volumio[1160]: info: Received an update from plugin. extracting info from payload Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:29 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.422+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.423+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.424+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.424+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.426+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.426+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=43 volume=70 Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.427+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:29.427+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:29 harmonmiller volumio[1160]: info: ------------------------------ 75ms Oct 13 19:23:29 harmonmiller volumio[1160]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 13 19:23:29 harmonmiller volumio[1160]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 13 19:23:29 harmonmiller volumio[1160]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 19:23:33 harmonmiller volumio[1160]: info: VolumeController::SetAlsaVolume55 Oct 13 19:23:33 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:23:33 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:33 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:33 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:33 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:33.947+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=4590 volume=55 Oct 13 19:23:33 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:33.947+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=4590 volume=55 Oct 13 19:23:33 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:33.949+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:33 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:33.949+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:34 harmonmiller volumio[1160]: info: VolumeController::SetAlsaVolume42 Oct 13 19:23:34 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:23:34 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:34 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:34 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:34 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:34.465+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=5092 volume=42 Oct 13 19:23:34 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:34.465+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=5092 volume=42 Oct 13 19:23:34 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:34.466+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:34 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:34.466+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:34 harmonmiller volumio[1160]: error: error Oct 13 19:23:41 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::stPlaybackTimer Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::serviceStop Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::serviceStop Oct 13 19:23:41 harmonmiller volumio[1160]: info: [1791915821697] ControllerWebradio::stop Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:23:41 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:23:41 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s266167&filter=s:~C:country Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.718+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.718+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.719+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.720+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id="https://online.classicrock.pt/stream1?type=http" title="Classic Rock Portugal" Oct 13 19:23:41 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:41 harmonmiller volumio[1160]: info: Oct 13 19:23:41 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:41 harmonmiller volumio[1160]: info: sendMpdCommand stop took 93 milliseconds Oct 13 19:23:41 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:41 harmonmiller volumio[1160]: info: sendMpdCommand status took 12 milliseconds Oct 13 19:23:41 harmonmiller volumio[1160]: info: sendMpdCommand status took 11 milliseconds Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:41 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 13 19:23:41 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:41 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: 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":"stream1?type=http","artist":"Classic Rock Portugal","album":null,"uri":"https://online.classicrock.pt/stream1?type=http","trackType":""} Oct 13 19:23:41 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService stop Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: No code Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:41 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:41 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.872+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.872+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.873+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title= Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.873+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title= Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.878+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.878+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.879+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title= Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.879+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title= Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.882+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.882+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=42 Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.883+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id= title= Oct 13 19:23:41 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:41.883+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id= title= Oct 13 19:23:41 harmonmiller volumio[1160]: info: ------------------------------ 107ms Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: [1791915822243] ControllerWebradio::clearAddPlayTrack Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand stop took 4 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:23:42 harmonmiller volumio[1160]: info: Oct 13 19:23:42 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:42 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand clear took 1 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "http://185.32.188.17:8011/stream" Oct 13 19:23:42 harmonmiller volumio[1160]: info: camilladsp respawn in 200 ms (attempt 2/10) Oct 13 19:23:42 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:23:42 harmonmiller volumio[1160]: info: ------------------------------ 6ms Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "http://185.32.188.17:8011/stream" Oct 13 19:23:42 harmonmiller volumio[1160]: info: Oct 13 19:23:42 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:42 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand add "http://185.32.188.17:8011/stream" took 1 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand play Oct 13 19:23:42 harmonmiller volumio[1160]: info: ------------------------------ 2ms Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand play took 2 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:42 harmonmiller volumio[1160]: info: Oct 13 19:23:42 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand status took 16 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:42 harmonmiller volumio[1160]: info: Oct 13 19:23:42 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand status took 22 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand status took 5 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand status took 4 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:42 harmonmiller volumio[1160]: 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":"stream","artist":null,"album":null,"uri":"http://185.32.188.17:8011/stream","trackType":""} Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus stop Oct 13 19:23:42 harmonmiller volumio[1160]: info: ------------------------------ 30ms Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:42 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:42 harmonmiller volumio[1160]: 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":"stream","artist":null,"album":null,"uri":"http://185.32.188.17:8011/stream","trackType":""} Oct 13 19:23:42 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus play Oct 13 19:23:42 harmonmiller volumio[1160]: info: Received an update from plugin. extracting info from payload Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:42 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.956+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=0 volume=42 Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.957+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=0 volume=42 Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.958+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.958+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.962+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=0 volume=42 Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.962+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=0 volume=42 Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.963+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:42 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:42.963+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:42 harmonmiller volumio[1160]: info: ------------------------------ 45ms Oct 13 19:23:43 harmonmiller volumio[1160]: info: Oct 13 19:23:43 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:23:43 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:23:43 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:43 harmonmiller volumio[1160]: info: Oct 13 19:23:43 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:23:43 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:23:43 harmonmiller volumio[1160]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 13 19:23:43 harmonmiller volumio[1160]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 13 19:23:43 harmonmiller volumio[1160]: info: sendMpdCommand status took 6 milliseconds Oct 13 19:23:43 harmonmiller volumio[1160]: info: ------------------------------ 11ms Oct 13 19:23:43 harmonmiller volumio[1160]: info: sendMpdCommand status took 6 milliseconds Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:23:43 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 19:23:43 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:23:43 harmonmiller volumio[1160]: info: ControllerMpd::pushState Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreCommandRouter::servicePushState Oct 13 19:23:43 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"stream","artist":"105 FM","album":null,"uri":"http://185.32.188.17:8011/stream","trackType":""} Oct 13 19:23:43 harmonmiller volumio[1160]: verbose: CURRENT POSITION 0 Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreStateMachine::syncState stateService play Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreStateMachine::syncState currentStatus play Oct 13 19:23:43 harmonmiller volumio[1160]: info: Received an update from plugin. extracting info from payload Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:43 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:43 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.176+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=250 volume=42 Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.176+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=250 volume=42 Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.177+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.178+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.183+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=250 volume=42 Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.183+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=250 volume=42 Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.184+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:43 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:43.185+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:43 harmonmiller volumio[1160]: info: ------------------------------ 81ms Oct 13 19:23:43 harmonmiller volumio[1160]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 19:23:54 harmonmiller volumio[1160]: info: VolumeController::SetAlsaVolume59 Oct 13 19:23:54 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:23:54 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:23:54 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:23:54 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:23:54 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:54.642+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_PLAYING positionMs=11778 volume=59 Oct 13 19:23:54 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:54.645+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_PLAYING positionMs=11778 volume=59 Oct 13 19:23:54 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:54.646+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:23:54 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:23:54.648+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.488+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.500+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=11.959307ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.544+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=54.786855ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.545+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=http://pushupdates.volumio.org duration=53.404252ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.546+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=56.628415ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.610+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=120.48161ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.611+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://www.googleapis.com duration=119.934841ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.633+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://functions.volumio.cloud duration=143.448716ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.638+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://securetoken.googleapis.com duration=148.822198ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.642+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://database.volumio.cloud duration=150.554227ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.659+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://functions.volumio.cloud duration=169.241182ms Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 19:24:07 harmonmiller volumio[1160]: info: Discovery: Getting this device information Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioGetState Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 19:24:07 harmonmiller volumio[1160]: verbose: New Socket.io Connection to 192.168.1.236:3000 from 192.168.1.164 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 13 19:24:07 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.826+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=https://google.com duration=336.443199ms Oct 13 19:24:07 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:07.996+01:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=http://cddb.volumio.org duration=505.983546ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 13 19:24:08 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:08.055+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" latency=-848.580821ms timeout=10s endpoint=http://plugins.volumio.org duration=565.235603ms Oct 13 19:24:10 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 19:24:10 harmonmiller volumio[1160]: info: TuneIn handleBrowseUri: tunein/browse/?id=r101286&filter=s:~C:country Oct 13 19:24:10 harmonmiller volumio[1160]: info: [TuneIn] Fetching (browse) results For tunein/browse/?id=r101286&filter=s:~C:country Oct 13 19:24:10 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:24:11 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::ClearQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::stPlaybackTimer Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::pushState Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushState Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::serviceStop Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::serviceStop Oct 13 19:24:11 harmonmiller volumio[1160]: info: [1791915851501] ControllerWebradio::stop Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::clearPlayQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::addQueueItems Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::addQueueItems Oct 13 19:24:11 harmonmiller volumio[1160]: info: Preload queue cleared Oct 13 19:24:11 harmonmiller volumio[1160]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s137149&filter=s:~C:country Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 19:24:11 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:11.516+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" state=STATUS_STOPPED positionMs=0 volume=59 Oct 13 19:24:11 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:11.516+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" state=STATUS_STOPPED positionMs=0 volume=59 Oct 13 19:24:11 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:11.518+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.135:56312 @ 0x1ca84b0" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:24:11 harmonmiller volumio5-onboarding[1792]: time=2026-10-13T19:24:11.518+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.164:57574,00:00:00:00:00:00%01 @ 0x1da6810" id=http://185.32.188.17:8011/stream title="Cascais Net Radio" Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPushQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::saveQueue Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::updateTrackBlock Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrackBlock Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreCommandRouter::volumioPlay Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::play index 0 Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::stop Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::play index undefined Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:24:11 harmonmiller volumio[1160]: info: CoreStateMachine::startPlaybackTimer Oct 13 19:24:11 harmonmiller volumio[1160]: info: CorePlayQueue::getTrack 0 Oct 13 19:24:11 harmonmiller volumio[1160]: info: [1791915851552] ControllerWebradio::clearAddPlayTrack Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 19:24:11 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:24:11 harmonmiller volumio[1160]: info: Oct 13 19:24:11 harmonmiller volumio[1160]: ---------------------------- MPD announces state update: player Oct 13 19:24:11 harmonmiller volumio[1160]: info: sendMpdCommand stop took 78 milliseconds Oct 13 19:24:11 harmonmiller volumio[1160]: info: ControllerMpd::getState Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand status Oct 13 19:24:11 harmonmiller volumio[1160]: info: sendMpdCommand stop took 28 milliseconds Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 19:24:11 harmonmiller volumio[1160]: info: Oct 13 19:24:11 harmonmiller volumio[1160]: ---------------------------- MPD announces system playlist update Oct 13 19:24:11 harmonmiller volumio[1160]: info: Ignoring MPD Status Update Oct 13 19:24:11 harmonmiller volumio[1160]: info: sendMpdCommand status took 11 milliseconds Oct 13 19:24:11 harmonmiller volumio[1160]: info: sendMpdCommand status took 9 milliseconds Oct 13 19:24:11 harmonmiller volumio[1160]: info: sendMpdCommand clear took 8 milliseconds Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::parseState Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 19:24:11 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand load "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:24:11 harmonmiller volumio[1160]: error: updateQueue error: null Oct 13 19:24:11 harmonmiller volumio[1160]: info: ------------------------------ 16ms Oct 13 19:24:12 harmonmiller volumio[1160]: info: camilladsp respawn in 400 ms (attempt 3/10) Oct 13 19:24:12 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 585 milliseconds Oct 13 19:24:12 harmonmiller volumio[1160]: info: sendMpdCommand playlistinfo took 584 milliseconds Oct 13 19:24:12 harmonmiller volumio[1160]: verbose: ControllerMpd::sendMpdCommand add "https://play.radioregional.pt:8220/stream/2/" Oct 13 19:24:12 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:24:12 harmonmiller volumio[1160]: verbose: ControllerMpd::parseTrackInfo Oct 13 19:24:12 harmonmiller volumio[1160]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 19:24:12 harmonmiller volumio[1160]: info: ------------------------------ 600ms Oct 13 19:24:12 harmonmiller volumio[1160]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 19:24:12 harmonmiller volumio[1160]: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 19:24:12 harmonmiller volumio[1160]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) Oct 13 19:24:12 harmonmiller volumio[1160]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 13 19:24:12 harmonmiller volumio[1160]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Oct 13 19:24:12 harmonmiller volumio[1160]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 19:24:12 harmonmiller sudo[10461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-13 19:23' Oct 13 19:24:12 harmonmiller sudo[10461]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"