-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Wed 2026-08-26 17:54:50 EDT. -- Aug 26 17:53:02 ken volumio[3325]: info: CoreCommandRouter::volumioGetQueue Aug 26 17:53:02 ken volumio[3325]: info: CoreStateMachine::getQueue Aug 26 17:53:02 ken volumio[3325]: info: CorePlayQueue::getQueue Aug 26 17:53:04 ken volumio[3325]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 17:53:04 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:15 ken volumio[3325]: Searching all installed plugins Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: , search Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 26 17:53:15 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 26 17:53:15 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 26 17:53:15 ken volumio[3325]: info: An error occurred while querying SHOUTCAST Aug 26 17:53:15 ken volumio[3325]: info: All search sources collected, pushing search results Aug 26 17:53:16 ken volumio[3325]: Searching all installed plugins Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: , search Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 26 17:53:16 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 26 17:53:16 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 26 17:53:16 ken volumio[3325]: info: All search sources collected, pushing search results Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 17:53:17 ken volumio[3325]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 26 17:53:17 ken volumio[3325]: info: Received Get System Version Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 17:53:17 ken volumio[3325]: info: Received Get System Info Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 17:53:17 ken volumio[3325]: info: Discovery: Getting this device information Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:17 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:17 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 17:53:19 ken volumio[3325]: Searching all installed plugins Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: , search Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 26 17:53:19 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 26 17:53:19 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 26 17:53:19 ken volumio[3325]: info: All search sources collected, pushing search results Aug 26 17:53:23 ken volumio[3325]: Searching all installed plugins Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: , search Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 26 17:53:23 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 26 17:53:23 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 26 17:53:24 ken volumio[3325]: info: All search sources collected, pushing search results Aug 26 17:53:29 ken volumio[3325]: info: Preload queue cleared Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::ClearQueue Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::stop Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::stPlaybackTimer Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::updateTrackBlock Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrackBlock Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::serviceStop Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: ControllerMpd::stop Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::clearPlayQueue Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::saveQueue Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushQueue Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::addQueueItems Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::addQueueItems Aug 26 17:53:29 ken volumio[3325]: info: Preload queue cleared Aug 26 17:53:29 ken volumio[3325]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s336532 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.706-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_STOPPED positionMs=0 volume=0 Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.707-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:53:29 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:29 ken volumio[3325]: info: Aug 26 17:53:29 ken volumio[3325]: ---------------------------- MPD announces state update: player Aug 26 17:53:29 ken volumio[3325]: info: sendMpdCommand stop took 49 milliseconds Aug 26 17:53:29 ken volumio[3325]: info: ControllerMpd::getState Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand status Aug 26 17:53:29 ken volumio[3325]: info: sendMpdCommand status took 3 milliseconds Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::parseState Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 17:53:29 ken volumio[3325]: info: sendMpdCommand playlistinfo took 5 milliseconds Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::parseTrackInfo Aug 26 17:53:29 ken volumio[3325]: info: ControllerMpd::pushState Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: 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":"Freddie Mercury - The Great Pretender","artist":"Bay Trust Radio","album":null,"uri":"http://hydra.shoutca.st:8064/stream","trackType":""} Aug 26 17:53:29 ken volumio[3325]: verbose: CURRENT POSITION 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::syncState stateService stop Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::syncState currentStatus stop Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:29 ken volumio[3325]: info: No code Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:29 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.778-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_STOPPED positionMs=0 volume=0 Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.779-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.780-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_STOPPED positionMs=0 volume=0 Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.781-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_STOPPED positionMs=0 volume=0 Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.781-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:53:29 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:29.782-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:53:29 ken volumio[3325]: info: ------------------------------ 49ms Aug 26 17:53:29 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:29 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:29 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:29 ken volumio[3325]: info: MCU Signalled Playback Inactive Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPushQueue Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::saveQueue Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::updateTrackBlock Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrackBlock Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioPlay Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::play index 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::stop Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::play index undefined Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreStateMachine::startPlaybackTimer Aug 26 17:53:29 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:29 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 26 17:53:29 ken volumio[3325]: info: [1787781209977] ControllerWebradio::clearAddPlayTrack Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 17:53:29 ken volumio[3325]: info: sendMpdCommand stop took 5 milliseconds Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand clear Aug 26 17:53:29 ken volumio[3325]: info: Aug 26 17:53:29 ken volumio[3325]: ---------------------------- MPD announces system playlist update Aug 26 17:53:29 ken volumio[3325]: info: Ignoring MPD Status Update Aug 26 17:53:29 ken volumio[3325]: info: sendMpdCommand clear took 2 milliseconds Aug 26 17:53:29 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand load "https://cast1.torontocast.com:4610/stream" Aug 26 17:53:29 ken volumio[3325]: error: updateQueue error: null Aug 26 17:53:29 ken volumio[3325]: info: ------------------------------ 6ms Aug 26 17:53:31 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand add "https://cast1.torontocast.com:4610/stream" Aug 26 17:53:31 ken volumio[3325]: info: Aug 26 17:53:31 ken volumio[3325]: ---------------------------- MPD announces system playlist update Aug 26 17:53:31 ken volumio[3325]: info: Ignoring MPD Status Update Aug 26 17:53:31 ken volumio[3325]: info: sendMpdCommand add "https://cast1.torontocast.com:4610/stream" took 2 milliseconds Aug 26 17:53:31 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 26 17:53:31 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand play Aug 26 17:53:31 ken volumio[3325]: info: ------------------------------ 3ms Aug 26 17:53:31 ken volumio[3325]: info: sendMpdCommand play took 1 milliseconds Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces state update: player Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::getState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand status Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces system playlist update Aug 26 17:53:32 ken volumio[3325]: info: Ignoring MPD Status Update Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces state update: player Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand status took 77 milliseconds Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::getState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand status Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 5ms Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand status took 3 milliseconds Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseTrackInfo Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: 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":"128 Kbps","isStreaming":false,"title":"stream","artist":"RDMIX CLASSIC ROCK","album":null,"uri":"https://cast1.torontocast.com:4610/stream","trackType":""} Aug 26 17:53:32 ken volumio[3325]: verbose: CURRENT POSITION 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState stateService play Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState currentStatus stop Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 86ms Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseTrackInfo Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1211,"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":"RDMIX CLASSIC ROCK","album":null,"uri":"https://cast1.torontocast.com:4610/stream","trackType":""} Aug 26 17:53:32 ken volumio[3325]: verbose: CURRENT POSITION 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState stateService play Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState currentStatus play Aug 26 17:53:32 ken volumio[3325]: info: Received an update from plugin. extracting info from payload Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.115-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=0 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.116-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id=https://cast1.torontocast.com:4610/stream title="RdMix Classic Rock" Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.117-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=0 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.118-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id=https://cast1.torontocast.com:4610/stream title="RdMix Classic Rock" Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 51ms Aug 26 17:53:32 ken volumio[3325]: info: Signalling Playback active due to playback status change Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces system playlist update Aug 26 17:53:32 ken volumio[3325]: info: Ignoring MPD Status Update Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces state update: player Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::getState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand status Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 5ms Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand status took 4 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseTrackInfo Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Nirvana - Heart-Shaped Box","artist":"RDMIX CLASSIC ROCK","album":null,"uri":"https://cast1.torontocast.com:4610/stream","trackType":""} Aug 26 17:53:32 ken volumio[3325]: verbose: CURRENT POSITION 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState stateService play Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::syncState currentStatus play Aug 26 17:53:32 ken volumio[3325]: info: Received an update from plugin. extracting info from payload Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.193-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=0 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.194-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id=https://cast1.torontocast.com:4610/stream title="Nirvana - Heart-Shaped Box" Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.195-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=0 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.195-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id=https://cast1.torontocast.com:4610/stream title="Nirvana - Heart-Shaped Box" Aug 26 17:53:32 ken pulseaudio[4090]: Support for resampler 'src-sinc-best-quality' not compiled in, reverting to 'auto'. Aug 26 17:53:32 ken pulseaudio[4090]: Cannot set requested source latency of 66.67 ms, adjusting to 135.29 ms Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 65ms Aug 26 17:53:32 ken volumio[3325]: info: Signalling Playback active due to playback status change Aug 26 17:53:32 ken volumio[3325]: info: Signalling Playback active due to playback status change Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: ------------------------------------ BT MESSAGE: BT STATUS: pending Aug 26 17:53:32 ken volumio[3325]: ------------------------------------ BT MESSAGE: BT STATUS: active Aug 26 17:53:32 ken volumio[3325]: BT PLUGIN MESSAGE: Playing: true Aug 26 17:53:32 ken volumio[3325]: BT PLUGIN MESSAGE: VOLATILE: undefined Aug 26 17:53:32 ken volumio[3325]: BT PLUGIN MESSAGE: STATE:undefined Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioStop Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::stop Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::stPlaybackTimer Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::updateTrackBlock Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrackBlock Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::serviceStop Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::serviceStop Aug 26 17:53:32 ken volumio[3325]: info: [1787781212340] ControllerWebradio::stop Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.343-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_STOPPED positionMs=0 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.344-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id=https://cast1.torontocast.com:4610/stream title="RdMix Classic Rock" Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: info: MCU Signalled Playback Active Aug 26 17:53:32 ken volumio[3325]: info: Aug 26 17:53:32 ken volumio[3325]: ---------------------------- MPD announces state update: player Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand stop took 81 milliseconds Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::getState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand status Aug 26 17:53:32 ken volumio[3325]: BT PLUGIN MESSAGE: BLUETOOTH: Starting Playback Routine Aug 26 17:53:32 ken volumio[3325]: info: Enabling Bluetooth Audio Output Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand status took 66 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseState Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 17:53:32 ken volumio[3325]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 26 17:53:32 ken volumio[3325]: verbose: ControllerMpd::parseTrackInfo Aug 26 17:53:32 ken volumio[3325]: info: ControllerMpd::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:53:32 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:53:32 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:53:32 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:53:32 ken volumio[3325]: info: CorePlayQueue::getTrack 0 Aug 26 17:53:32 ken volumio[3325]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.534-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=1450000 volume=0 Aug 26 17:53:32 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:32.535-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:53:32 ken volumio[3325]: info: ------------------------------ 124ms Aug 26 17:53:32 ken volumio[3325]: info: Signalling Playback active due to playback status change Aug 26 17:53:32 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:53:32 ken volumio[3325]: info: MCU Signalled Playback Inactive Aug 26 17:53:32 ken volumio[3325]: info: MCU Signalled Playback Active Aug 26 17:53:32 ken pulseaudio[4090]: Configured latency of 200.00 ms is smaller than minimum latency, using minimum instead Aug 26 17:53:32 ken pulseaudio[4090]: Cannot set requested sink latency of 337.51 ms, adjusting to 600.00 ms Aug 26 17:53:32 ken volumio[3325]: info: Bluetooth Audio successfully Enabled Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.386-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=7.240475ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.406-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.423-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=16.443491ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.435-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=27.027471ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.445-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=36.594031ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.454-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://securetoken.googleapis.com duration=46.52026ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.456-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=48.891848ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.470-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://google.com duration=62.790501ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.475-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://database.volumio.cloud duration=65.890882ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.484-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://functions.volumio.cloud duration=75.793901ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.486-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://functions.volumio.cloud duration=75.827693ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.521-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=http://pushupdates.volumio.org duration=111.70114ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.530-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=https://www.googleapis.com duration=123.441038ms Aug 26 17:53:41 ken sudo[10994]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 17:53:41 ken sudo[10994]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:53:41 ken sudo[10994]: pam_unix(sudo:session): session closed for user root Aug 26 17:53:41 ken sudo[10997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 17:53:41 ken sudo[10997]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:53:41 ken sudo[10997]: pam_unix(sudo:session): session closed for user root Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.717-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=http://cddb.volumio.org duration=308.686367ms Aug 26 17:53:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:53:41.735-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=5.425591ms timeout=10s endpoint=http://plugins.volumio.org duration=325.410734ms Aug 26 17:53:41 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144 from 10.0.0.191 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 17:53:41 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 17:53:41 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 17:53:41 ken sudo[11002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 17:53:41 ken sudo[11002]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:53:41 ken sudo[11002]: pam_unix(sudo:session): session closed for user root Aug 26 17:53:41 ken sudo[11005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 17:53:41 ken sudo[11005]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:53:41 ken sudo[11005]: pam_unix(sudo:session): session closed for user root Aug 26 17:53:41 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144 from 10.0.0.191 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 17:53:42 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 26 17:53:42 ken volumio[3325]: info: Listing playlists Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 17:53:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 17:53:43 ken pulseaudio[4090]: Too many underruns, increasing latency to 815.32 ms Aug 26 17:53:43 ken volumio[3325]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 17:53:43 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:53:43 ken volumio[3325]: info: CoreCommandRouter::volumioGetQueue Aug 26 17:53:43 ken volumio[3325]: info: CoreStateMachine::getQueue Aug 26 17:53:43 ken volumio[3325]: info: CorePlayQueue::getQueue Aug 26 17:53:58 ken volumio[3325]: ------------------------------------ BT MESSAGE: BT STATUS: idle Aug 26 17:54:25 ken volumio[3325]: ------------------------------------ BT MESSAGE: BT STATUS: pending Aug 26 17:54:25 ken volumio[3325]: ------------------------------------ BT MESSAGE: BT STATUS: active Aug 26 17:54:25 ken volumio[3325]: BT PLUGIN MESSAGE: Playing: true Aug 26 17:54:25 ken volumio[3325]: BT PLUGIN MESSAGE: VOLATILE: undefined Aug 26 17:54:25 ken volumio[3325]: BT PLUGIN MESSAGE: STATE:undefined Aug 26 17:54:25 ken volumio[3325]: info: CoreCommandRouter::volumioStop Aug 26 17:54:25 ken volumio[3325]: info: CoreStateMachine::stop Aug 26 17:54:25 ken volumio[3325]: info: CoreStateMachine::serviceStop Aug 26 17:54:25 ken volumio[3325]: info: Received STOP, but no service to execute it Aug 26 17:54:25 ken volumio[3325]: BT PLUGIN MESSAGE: BLUETOOTH: Starting Playback Routine Aug 26 17:54:25 ken volumio[3325]: info: Enabling Bluetooth Audio Output Aug 26 17:54:25 ken pulseaudio[4090]: Support for resampler 'src-sinc-best-quality' not compiled in, reverting to 'auto'. Aug 26 17:54:25 ken pulseaudio[4090]: Configured latency of 200.00 ms is smaller than minimum latency, using minimum instead Aug 26 17:54:25 ken pulseaudio[4090]: Cannot set requested sink latency of 337.51 ms, adjusting to 600.00 ms Aug 26 17:54:25 ken pulseaudio[4090]: Cannot set requested source latency of 105.16 ms, adjusting to 135.29 ms Aug 26 17:54:25 ken volumio[3325]: info: CoreCommandRouter::servicePushState Aug 26 17:54:25 ken volumio[3325]: info: CoreStateMachine::pushState Aug 26 17:54:25 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 17:54:25 ken volumio[3325]: info: CoreCommandRouter::volumioPushState Aug 26 17:54:25 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:54:25 ken volumio[3325]: info: MRS: Pushing multiroomSync output update for this device Aug 26 17:54:25 ken volumio[3325]: info: MRS: Pushing multiroomSync output Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.829-04:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" state=STATUS_PLAYING positionMs=1504000 volume=0 Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.830-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" id= title= Aug 26 17:54:25 ken volumio[3325]: info: Signalling Playback active due to playback status change Aug 26 17:54:25 ken volumio[3325]: info: Updating RAAT Signal Path Aug 26 17:54:25 ken pulseaudio[4090]: Failed to load module "module-alsa-sink" (argument: "device=volumio"): initialization failed. Aug 26 17:54:25 ken volumio[3325]: error: Cannot load module of audio hardware: Error: Command failed: /usr/bin/pactl load-module module-alsa-sink device=volumio Aug 26 17:54:25 ken volumio[3325]: No protocol specified Aug 26 17:54:25 ken volumio[3325]: xcb_connection_has_error() returned true Aug 26 17:54:25 ken volumio[3325]: Failure: Module initialization failed Aug 26 17:54:25 ken volumio[3325]: No protocol specified Aug 26 17:54:25 ken volumio[3325]: xcb_connection_has_error() returned true Aug 26 17:54:25 ken volumio[3325]: BT PLUGIN MESSAGE: SINK LOADED: 6 Aug 26 17:54:25 ken volumio[3325]: info: Alsa Sink Already Loaded Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.966-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.981-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=14.820821ms Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.995-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=25.647716ms Aug 26 17:54:25 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:25.999-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=30.038891ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.013-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://securetoken.googleapis.com duration=45.029087ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.032-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://functions.volumio.cloud duration=63.888331ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.034-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=64.751166ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.035-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://database.volumio.cloud duration=64.544499ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.037-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://functions.volumio.cloud duration=66.356961ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.066-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://google.com duration=98.627023ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.079-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=http://pushupdates.volumio.org duration=108.093374ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.089-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=https://www.googleapis.com duration=121.434525ms Aug 26 17:54:26 ken pulseaudio[4090]: Too many underruns, increasing latency to 815.32 ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.238-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=http://plugins.volumio.org duration=268.234433ms Aug 26 17:54:26 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:26.375-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=12.042436ms timeout=10s endpoint=http://cddb.volumio.org duration=405.512822ms Aug 26 17:54:27 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144 from 10.0.0.191 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Aug 26 17:54:27 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:54:27 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 17:54:27 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 26 17:54:27 ken volumio[3325]: info: Listing playlists Aug 26 17:54:27 ken volumio[3325]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 17:54:27 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 17:54:27 ken volumio[3325]: info: CoreCommandRouter::volumioGetQueue Aug 26 17:54:27 ken volumio[3325]: info: CoreStateMachine::getQueue Aug 26 17:54:27 ken volumio[3325]: info: CorePlayQueue::getQueue Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 17:54:28 ken volumio[3325]: info: Discovery: Getting this device information Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 17:54:28 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144:3000 from 10.0.0.191 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 17:54:28 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.372-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.989688ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.395-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.410-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=14.440778ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.424-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=26.562342ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.429-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=32.061977ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.444-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=47.732383ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.445-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://securetoken.googleapis.com duration=48.264759ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.456-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://google.com duration=60.450199ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.460-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://functions.volumio.cloud duration=63.199203ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.469-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://functions.volumio.cloud duration=70.578676ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.495-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://database.volumio.cloud duration=96.252225ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.512-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=http://pushupdates.volumio.org duration=113.068715ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.520-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=https://www.googleapis.com duration=123.337818ms Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.638-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=http://plugins.volumio.org duration=239.583539ms Aug 26 17:54:41 ken sudo[11163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 17:54:41 ken sudo[11163]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:54:41 ken sudo[11163]: pam_unix(sudo:session): session closed for user root Aug 26 17:54:41 ken sudo[11165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 17:54:41 ken sudo[11165]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:54:41 ken sudo[11165]: pam_unix(sudo:session): session closed for user root Aug 26 17:54:41 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144 from 10.0.0.191 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Aug 26 17:54:41 ken volumio5-onboarding[3864]: time=2026-08-26T17:54:41.766-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="10.0.0.191:60437,00:00:00:00:00:00%04 @ 0x290a150" latency=4.741264ms timeout=10s endpoint=http://cddb.volumio.org duration=368.689869ms Aug 26 17:54:41 ken sudo[11171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 17:54:41 ken sudo[11171]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:54:41 ken sudo[11171]: pam_unix(sudo:session): session closed for user root Aug 26 17:54:41 ken sudo[11175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 17:54:41 ken sudo[11175]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 17:54:41 ken sudo[11175]: pam_unix(sudo:session): session closed for user root Aug 26 17:54:42 ken volumio[3325]: verbose: New Socket.io Connection to 10.0.0.144 from 10.0.0.191 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::volumioGetState Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 17:54:42 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 26 17:54:42 ken volumio[3325]: info: Listing playlists Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 26 17:54:42 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 26 17:54:49 ken volumio[3325]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Aug 26 17:54:49 ken volumio[3325]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Aug 26 17:54:49 ken volumio[3325]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 17:54:49 ken volumio[3325]: TypeError: Cannot read property 'then' of undefined Aug 26 17:54:49 ken volumio[3325]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Aug 26 17:54:49 ken volumio[3325]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Aug 26 17:54:49 ken volumio[3325]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Aug 26 17:54:49 ken volumio[3325]: at Socket.emit (events.js:400:28) Aug 26 17:54:49 ken volumio[3325]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 26 17:54:49 ken volumio[3325]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Aug 26 17:54:49 ken volumio[3325]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 17:54:50 ken sudo[11228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-26 17:53 Aug 26 17:54:50 ken sudo[11228]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:19:27 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="a7285124ffc88c43265bb2db03526f6a"