Mar 24 21:24:01 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 21:24:01 volumioras4 volumio[1227]: info: Received Get System Info Mar 24 21:24:01 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 21:24:01 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 21:24:01 volumioras4 volumio[1227]: info: Discovery: Getting this device information Mar 24 21:24:01 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetState Mar 24 21:24:01 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 21:24:02 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Mar 24 21:24:02 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Mar 24 21:24:02 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Mar 24 21:24:03 volumioras4 volumio[1227]: info: Mar 24 21:24:03 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:03 volumioras4 volumio[1227]: info: Mar 24 21:24:03 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:03 volumioras4 volumio[1227]: info: Mar 24 21:24:03 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:03 volumioras4 volumio[1227]: info: Mar 24 21:24:03 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand status took 15 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand status took 9 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand status took 5 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand status took 38 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 15 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49371,"duration":438,"samplerate":"192 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"9216 Kbps","isStreaming":false,"title":"Medley: Autumn In New York","artist":"Eric Reed","album":"Manhattan Melodies","uri":"http://192.168.1.29:49152/audirvana/audio_f_0.wav","trackType":"wav"} Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService pause Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::stPlaybackTimer Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49371,"duration":438,"samplerate":"192 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"9216 Kbps","isStreaming":false,"title":"Medley: Autumn In New York","artist":"Eric Reed","album":"Manhattan Melodies","uri":"http://192.168.1.29:49152/audirvana/audio_f_0.wav","trackType":"wav"} Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService pause Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::stPlaybackTimer Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49371,"duration":438,"samplerate":"192 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"9216 Kbps","isStreaming":false,"title":"Medley: Autumn In New York","artist":"Eric Reed","album":"Manhattan Melodies","uri":"http://192.168.1.29:49152/audirvana/audio_f_0.wav","trackType":"wav"} Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService pause Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::stPlaybackTimer Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.879+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PAUSED positionMs=0 volume=46 Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.879+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_0.wav title="Medley: Autumn In New York" Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.897+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PAUSED positionMs=0 volume=46 Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.898+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_0.wav title="Medley: Autumn In New York" Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.901+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PAUSED positionMs=0 volume=46 Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.901+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_0.wav title="Medley: Autumn In New York" Mar 24 21:24:03 volumioras4 volumio[1227]: info: ------------------------------ 211ms Mar 24 21:24:03 volumioras4 volumio[1227]: info: ------------------------------ 210ms Mar 24 21:24:03 volumioras4 volumio[1227]: info: ------------------------------ 205ms Mar 24 21:24:03 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 163 milliseconds Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:24:03 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49371,"duration":438,"samplerate":"192 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"9216 Kbps","isStreaming":false,"title":"Medley: Autumn In New York","artist":"Eric Reed","album":"Manhattan Melodies","uri":"http://192.168.1.29:49152/audirvana/audio_f_0.wav","trackType":"wav"} Mar 24 21:24:03 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService pause Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:03 volumioras4 volumio[1227]: info: CoreStateMachine::stPlaybackTimer Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.995+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PAUSED positionMs=0 volume=46 Mar 24 21:24:03 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:03.995+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_0.wav title="Medley: Autumn In New York" Mar 24 21:24:03 volumioras4 volumio[1227]: info: ------------------------------ 266ms Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:24:04 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:24:07 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 21:24:13 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Mar 24 21:24:13 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 24 21:24:16 volumioras4 volumio[1227]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 24 21:24:16 volumioras4 volumio[1227]: info: Received Get System Version Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 21:24:16 volumioras4 volumio[1227]: info: Received Get System Info Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 21:24:16 volumioras4 volumio[1227]: info: Discovery: Getting this device information Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetState Mar 24 21:24:16 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 21:24:23 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Mar 24 21:24:23 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Mar 24 21:24:33 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Mar 24 21:24:33 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Mar 24 21:24:43 volumioras4 kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Mar 24 21:24:49 volumioras4 volumio[1227]: info: Clearing queue after UPNP request Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::ClearQueue Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::stPlaybackTimer Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::updateTrackBlock Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrackBlock Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::serviceStop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::stop Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::clearPlayQueue Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::saveQueue Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushQueue Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.373+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.373+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.390+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.390+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:49 volumioras4 volumio[1227]: info: sendMpdCommand stop took 82 milliseconds Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:49 volumioras4 volumio[1227]: info: Mar 24 21:24:49 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:24:49 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:49 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:49 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:49 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 38ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: sendMpdCommand status took 37 milliseconds Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 37ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: sendMpdCommand status took 15 milliseconds Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 15ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: sendMpdCommand status took 14 milliseconds Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: sendMpdCommand status took 17 milliseconds Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: No code Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: No code Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: No code Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 24 21:24:49 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus stop Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: No code Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:24:49 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:49 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.700+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.700+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.722+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.722+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.727+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.727+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.731+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.731+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.734+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.734+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.752+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.752+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.756+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.756+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.761+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.761+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.771+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.771+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.822+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.822+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.824+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.824+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.826+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:49 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:49.826+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 553ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 532ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 530ms Mar 24 21:24:49 volumioras4 volumio[1227]: info: ------------------------------ 520ms Mar 24 21:24:50 volumioras4 volumio[1227]: info: Clearing queue after UPNP request Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreStateMachine::ClearQueue Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreStateMachine::stop Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 21:24:50 volumioras4 volumio[1227]: info: CorePlayQueue::clearPlayQueue Mar 24 21:24:50 volumioras4 volumio[1227]: info: CorePlayQueue::saveQueue Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushQueue Mar 24 21:24:50 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:50.628+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:24:50 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:24:50.628+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:24:50 volumioras4 volumio[1227]: info: Mar 24 21:24:50 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Mar 24 21:24:50 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Mar 24 21:24:50 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Mar 24 21:24:50 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:24:50 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:24:50 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:50 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:50 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:50 volumioras4 volumio[1227]: info: ------------------------------ 29ms Mar 24 21:24:50 volumioras4 volumio[1227]: info: ------------------------------ 11ms Mar 24 21:24:50 volumioras4 volumio[1227]: info: ------------------------------ 10ms Mar 24 21:24:50 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:24:50 volumioras4 volumio[1227]: info: ------------------------------ 11ms Mar 24 21:24:50 volumioras4 volumio[1227]: info: Starting UPNP Playback Mar 24 21:24:50 volumioras4 volumio[1227]: info: Preparing playback through UPNP Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetState Mar 24 21:24:50 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:24:50 volumioras4 volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 24 21:25:28 volumioras4 ntpd[1008]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 24 21:25:28 volumioras4 ntpd[1008]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Mar 24 21:25:28 volumioras4 ntpd[1008]: DNS: Pool skipping: 193.253.114.38 Mar 24 21:25:28 volumioras4 ntpd[1008]: DNS: Pool skipping: 80.69.209.3 Mar 24 21:25:28 volumioras4 ntpd[1008]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool skipping: 193.253.114.38 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool skipping: 80.69.209.3 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool skipping: 2a12:bec4:1da0:3e::123 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool taking: 2c0f:f530:20:a::123 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool taking: 2a05:f480:3000:2a20:5400:5ff:fe82:8678 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: Pool taking: 2001:43f8:1f5:100::58 Mar 24 21:25:29 volumioras4 ntpd[1008]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Mar 24 21:25:30 volumioras4 ntpd[1008]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 24 21:25:30 volumioras4 ntpd[1008]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Mar 24 21:25:30 volumioras4 ntpd[1008]: DNS: Pool skipping: 193.253.114.38 Mar 24 21:25:30 volumioras4 ntpd[1008]: DNS: Pool skipping: 80.69.209.3 Mar 24 21:25:30 volumioras4 ntpd[1008]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Mar 24 21:25:31 volumioras4 ntpd[1008]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 24 21:25:31 volumioras4 ntpd[1008]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Mar 24 21:25:31 volumioras4 ntpd[1008]: DNS: Pool skipping: 193.253.114.38 Mar 24 21:25:31 volumioras4 ntpd[1008]: DNS: Pool skipping: 80.69.209.3 Mar 24 21:25:31 volumioras4 ntpd[1008]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Mar 24 21:25:42 volumioras4 volumio[1227]: info: Clearing queue after UPNP request Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::ClearQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::stop Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::clearPlayQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::saveQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushQueue Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.050+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_STOPPED positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.050+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id= title= Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:25:43 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:25:43 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: error: updateQueue error: null Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 1ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Starting UPNP Playback Mar 24 21:25:43 volumioras4 volumio[1227]: info: Preparing playback through UPNP Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getTrack 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 5ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 4ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 6ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 5ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 4ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 4ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces system playlist update Mar 24 21:25:43 volumioras4 volumio[1227]: info: Ignoring MPD Status Update Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 3ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 2ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 6 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 11 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 10 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 9 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 5 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 3 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 2 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus stop Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 18ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: Mar 24 21:25:43 volumioras4 volumio[1227]: ---------------------------- MPD announces state update: player Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::getState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand status Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.877+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.877+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.878+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.878+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.879+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.879+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.880+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.880+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.881+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.882+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.883+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.883+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.884+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.884+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.885+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.885+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.886+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.886+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.887+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.887+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.888+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.888+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.889+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.889+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 94ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 92ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 91ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 89ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 86ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 86ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand status took 79 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: ControllerMpd::parseTrackInfo Mar 24 21:25:43 volumioras4 volumio[1227]: info: ControllerMpd::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::servicePushState Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: In UPNP mode Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":625,"samplerate":"192 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Body And Soul (Live - Instrumental)","artist":"Charlie Haden","album":"Night And The City","uri":"http://192.168.1.29:49152/audirvana/audio_f_2.wav","trackType":"wav"} Mar 24 21:25:43 volumioras4 volumio[1227]: verbose: CURRENT POSITION 0 Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState stateService play Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::syncState currentStatus play Mar 24 21:25:43 volumioras4 volumio[1227]: info: Received an update from plugin. extracting info from payload Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::pushState Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioPushState Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.936+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.937+04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" state=STATUS_PLAYING positionMs=0 volume=46 Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.937+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio5-onboarding[1523]: time=2026-03-24T21:25:43.938+04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:42708 @ 0x30d07b0" id=http://192.168.1.29:49152/audirvana/audio_f_2.wav title="Body And Soul (Live - Instrumental)" Mar 24 21:25:43 volumioras4 volumio[1227]: info: ------------------------------ 112ms Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreCommandRouter::volumioGetQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CoreStateMachine::getQueue Mar 24 21:25:43 volumioras4 volumio[1227]: info: CorePlayQueue::getQueue Mar 24 21:25:45 volumioras4 volumio[1227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 21:25:45 volumioras4 volumio[1227]: Error: certificate is not yet valid Mar 24 21:25:45 volumioras4 volumio[1227]: at TLSSocket.onConnectSecure (node:_tls_wrap:1627:34) Mar 24 21:25:45 volumioras4 volumio[1227]: at TLSSocket.emit (node:events:514:28) Mar 24 21:25:45 volumioras4 volumio[1227]: at TLSSocket._finishInit (node:_tls_wrap:1038:8) Mar 24 21:25:45 volumioras4 volumio[1227]: at ssl.onhandshakedone (node:_tls_wrap:824:12) { Mar 24 21:25:45 volumioras4 volumio[1227]: code: 'CERT_NOT_YET_VALID' Mar 24 21:25:45 volumioras4 volumio[1227]: } Mar 24 21:25:45 volumioras4 volumio[1227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 21:25:45 volumioras4 sudo[2931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 21:24' Mar 24 21:25:45 volumioras4 sudo[2931]: 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"