Mar 26 18:03:03 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:05 volumio go-librespot[1796]: time="2026-03-26T18:03:05+02:00" level=trace msg="sent dealer ping" Mar 26 18:03:05 volumio go-librespot[1796]: time="2026-03-26T18:03:05+02:00" level=trace msg="received dealer pong" Mar 26 18:03:07 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:11 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:15 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:19 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:19 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: Mar 26 18:03:19 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:19 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:03:19 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:03:20 volumio volumio[1334]: info: sendMpdCommand status took 458 milliseconds Mar 26 18:03:20 volumio volumio[1334]: info: sendMpdCommand status took 433 milliseconds Mar 26 18:03:20 volumio volumio[1334]: info: sendMpdCommand status took 465 milliseconds Mar 26 18:03:20 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:20 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:03:20 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:20 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:20 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: 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 26 18:03:20 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio[1334]: info: No code Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: 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 26 18:03:20 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio[1334]: info: No code Mar 26 18:03:20 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:20 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:20 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.572+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.572+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.584+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.585+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.586+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.586+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.610+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.610+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.615+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.616+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.619+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:20 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:20.620+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:20 volumio volumio[1334]: info: ------------------------------ 1072ms Mar 26 18:03:20 volumio volumio[1334]: info: ------------------------------ 1073ms Mar 26 18:03:20 volumio volumio[1334]: info: sendMpdCommand status took 1327 milliseconds Mar 26 18:03:21 volumio volumio[1334]: info: sendMpdCommand status took 1342 milliseconds Mar 26 18:03:21 volumio volumio[1334]: info: sendMpdCommand status took 1342 milliseconds Mar 26 18:03:21 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:21 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:03:21 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:21 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:21 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: 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 26 18:03:21 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio[1334]: info: No code Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: 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 26 18:03:21 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio[1334]: info: No code Mar 26 18:03:21 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:21 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:21 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.302+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.302+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.308+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.308+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.316+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.316+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.324+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.324+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.331+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.332+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.338+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:21 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:21.338+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:21 volumio volumio[1334]: info: ------------------------------ 1844ms Mar 26 18:03:21 volumio volumio[1334]: info: ------------------------------ 1848ms Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:21 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: info: sendMpdCommand status took 2545 milliseconds Mar 26 18:03:22 volumio volumio[1334]: info: sendMpdCommand status took 2508 milliseconds Mar 26 18:03:22 volumio volumio[1334]: info: sendMpdCommand status took 2507 milliseconds Mar 26 18:03:22 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:22 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:03:22 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:22 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:03:22 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: 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 26 18:03:22 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio[1334]: info: No code Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: 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 26 18:03:22 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio[1334]: info: No code Mar 26 18:03:22 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:03:22 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:03:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.618+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.618+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.628+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.628+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.645+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.646+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.647+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.647+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.650+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.651+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.662+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:03:22 volumio volumio5-onboarding[1636]: time=2026-03-26T18:03:22.663+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:03:22 volumio volumio[1334]: info: ------------------------------ 3147ms Mar 26 18:03:22 volumio volumio[1334]: info: ------------------------------ 3183ms Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:22 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:03:23 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:27 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:31 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:34 volumio go-librespot[1796]: time="2026-03-26T18:03:34+02:00" level=trace msg="received accesspoint ping" Mar 26 18:03:34 volumio go-librespot[1796]: time="2026-03-26T18:03:34+02:00" level=trace msg="received accesspoint pong ack" Mar 26 18:03:35 volumio go-librespot[1796]: time="2026-03-26T18:03:35+02:00" level=trace msg="sent dealer ping" Mar 26 18:03:35 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:35 volumio go-librespot[1796]: time="2026-03-26T18:03:35+02:00" level=trace msg="received dealer pong" Mar 26 18:03:39 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:43 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:47 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:51 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:55 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:03:59 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:04:03 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:04:05 volumio go-librespot[1796]: time="2026-03-26T18:04:05+02:00" level=trace msg="sent dealer ping" Mar 26 18:04:05 volumio go-librespot[1796]: time="2026-03-26T18:04:05+02:00" level=trace msg="received dealer pong" Mar 26 18:04:07 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand update Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: info: Mar 26 18:04:11 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand update took 10 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: info: Mar 26 18:04:11 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: info: Mar 26 18:04:11 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 8 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 6 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 5 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 4 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 4 milliseconds Mar 26 18:04:11 volumio volumio[1334]: info: sendMpdCommand status took 3 milliseconds Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio ntfs-3g[1517]: Could not decode the type of inode 267 Mar 26 18:04:11 volumio volumio[1334]: info: Command Router : Notfying DB Updatetrue Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio volumio[1334]: info: Command Router : Notfying DB Updatetrue Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio volumio[1334]: info: Command Router : Notfying DB Updatetrue Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:11 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 26 18:04:11 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: No code Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 26 18:04:11 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: No code Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 26 18:04:11 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio[1334]: info: No code Mar 26 18:04:11 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:11 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:11 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.841+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.841+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.842+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.842+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.843+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.843+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.844+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.844+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.845+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.845+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.846+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.846+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.847+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.847+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.850+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.850+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.851+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:11 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:11.851+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:11 volumio volumio[1334]: info: ------------------------------ 233ms Mar 26 18:04:11 volumio volumio[1334]: info: ------------------------------ 230ms Mar 26 18:04:11 volumio volumio[1334]: info: ------------------------------ 229ms Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:11 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: MPD Database updated - AlbumList cache refreshed Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: database Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: Mar 26 18:04:13 volumio volumio[1334]: ---------------------------- MPD announces state update: update Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::getState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::sendMpdCommand status Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 115 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 115 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 116 milliseconds Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.589+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.590+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.590+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.591+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.591+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.591+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.592+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.593+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.593+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.593+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.597+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.597+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio[1334]: info: ------------------------------ 254ms Mar 26 18:04:13 volumio volumio[1334]: info: ------------------------------ 255ms Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 352 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 351 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 350 milliseconds Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.815+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.816+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.817+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.817+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.819+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.820+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.820+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.821+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.822+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.822+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.823+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.824+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio[1334]: info: ------------------------------ 484ms Mar 26 18:04:13 volumio volumio[1334]: info: ------------------------------ 481ms Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 524 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 523 milliseconds Mar 26 18:04:13 volumio volumio[1334]: info: sendMpdCommand status took 523 milliseconds Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: Command Router : Notfying DB Updatefalse Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::Close All Modals sent Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: verbose: ControllerMpd::parseState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: ControllerMpd::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::servicePushState Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: 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 26 18:04:13 volumio volumio[1334]: verbose: CURRENT POSITION 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState stateService stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::syncState currentStatus stop Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio[1334]: info: No code Mar 26 18:04:13 volumio volumio[1334]: info: CoreStateMachine::pushState Mar 26 18:04:13 volumio volumio[1334]: info: CorePlayQueue::getTrack 0 Mar 26 18:04:13 volumio volumio[1334]: info: CoreCommandRouter::volumioPushState Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.965+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.965+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.966+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.967+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.968+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.968+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.969+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.969+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.970+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.971+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.971+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" state=STATUS_STOPPED positionMs=0 volume=50 Mar 26 18:04:13 volumio volumio5-onboarding[1636]: time=2026-03-26T18:04:13.972+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.8.147:55999,00:00:00:00:00:00%01 @ 0x308cb70" id= title= Mar 26 18:04:14 volumio volumio[1334]: info: ------------------------------ 623ms Mar 26 18:04:14 volumio volumio[1334]: info: ------------------------------ 624ms Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:14 volumio volumio[1334]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 26 18:04:18 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 18:04:18 volumio volumio[1334]: info: CURURI: music-library Mar 26 18:04:18 volumio volumio[1334]: info: Preload queue cleared Mar 26 18:04:19 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 18:04:19 volumio volumio[1334]: info: CURURI: music-library/USB Mar 26 18:04:19 volumio volumio[1334]: info: Preload queue cleared Mar 26 18:04:20 volumio volumio[1334]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 18:04:20 volumio volumio[1334]: info: CURURI: music-library/USB/Cdrive Mar 26 18:04:20 volumio volumio[1334]: info: Preload queue cleared Mar 26 18:04:20 volumio volumio[1334]: info: Preloading song: music-library/USB/Cdrive/SQ-ST0013.WAV Mar 26 18:04:20 volumio volumio[1334]: info: Preloading song: music-library/USB/Cdrive/SQ-ST030.WAV Mar 26 18:04:20 volumio volumio[1334]: info: Exploding uri music-library/USB/Cdrive/SQ-ST0013.WAV in service mpd Mar 26 18:04:20 volumio volumio[1334]: info: ALBUMART /albumart?cacheid=139&web=//extralarge&path=%2Fmnt%2FUSB%2FCdrive%2FSQ-ST0013.WAV&metadata=false Mar 26 18:04:20 volumio volumio[1334]: info: URI /mnt/USB/Cdrive/SQ-ST0013.WAV Mar 26 18:04:20 volumio volumio[1334]: info: Exploding uri music-library/USB/Cdrive/SQ-ST030.WAV in service mpd Mar 26 18:04:20 volumio volumio[1334]: info: ALBUMART /albumart?cacheid=139&web=//extralarge&path=%2Fmnt%2FUSB%2FCdrive%2FSQ-ST030.WAV&metadata=false Mar 26 18:04:20 volumio volumio[1334]: info: URI /mnt/USB/Cdrive/SQ-ST030.WAV Mar 26 18:04:22 volumio volumio[1334]: info: Preload queue cleared Mar 26 18:04:22 volumio volumio[1334]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 18:04:22 volumio volumio[1334]: info: CoreStateMachine::ClearQueue Mar 26 18:04:22 volumio volumio[1334]: info: CoreStateMachine::stop Mar 26 18:04:22 volumio volumio[1334]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 18:04:22 volumio volumio[1334]: info: CorePlayQueue::clearPlayQueue Mar 26 18:04:22 volumio volumio[1334]: info: CorePlayQueue::saveQueue Mar 26 18:04:22 volumio volumio[1334]: info: CoreCommandRouter::volumioPushQueue Mar 26 18:04:22 volumio volumio[1334]: info: CoreStateMachine::addQueueItems Mar 26 18:04:22 volumio volumio[1334]: info: CorePlayQueue::addQueueItems Mar 26 18:04:22 volumio volumio[1334]: info: Preload queue cleared Mar 26 18:04:22 volumio volumio[1334]: info: Adding Item to queue: music-library/USB/Cdrive/Burmester - DEMO CD3 Mar 26 18:04:22 volumio volumio[1334]: info: Exploding uri music-library/USB/Cdrive/Burmester - DEMO CD3 in service mpd Mar 26 18:04:22 volumio volumio[1334]: info: ALBUMART /albumart?cacheid=139&web=//extralarge&path=%2Fmnt%2FUSB%2FCdrive%2FBurmester%20-%20DEMO%20CD3%2FCDImage.ape&metadata=false Mar 26 18:04:22 volumio volumio[1334]: info: URI /mnt/USB/Cdrive/Burmester - DEMO CD3/CDImage.ape Mar 26 18:04:22 volumio volumio[1334]: info: ALBUMART /albumart?cacheid=139&web=Melissa%20Walker/Burmester%20Reference%20CD%20III/extralarge&path=%2Fmnt%2FUSB%2FCdrive%2FBurmester%20-%20DEMO%20CD3%2FCDImage.ape.cue&metadata=false Mar 26 18:04:22 volumio volumio[1334]: info: URI /mnt/USB/Cdrive/Burmester - DEMO CD3/CDImage.ape.cue Mar 26 18:04:22 volumio volumio[1334]: info: ALBUMART /albumart?cacheid=139&web=Nicolo%20Paganini%20by%20Gil%20Shaham%20und%20Goran%20Sollscher/Burmester%20Reference%20CD%20III/extralarge&path=%2Fmnt%2FUSB%2FCdrive%2FBurmester%20-%20DEMO%20CD3%2FCDImage.ape.cue&metadata=false Mar 26 18:04:22 volumio volumio[1334]: info: URI /mnt/USB/Cdrive/Burmester - DEMO CD3/CDImage.ape.cue Mar 26 18:04:22 volumio volumio[1334]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 18:04:22 volumio volumio[1334]: Error: Unable to resolve or reject the same promise twice Mar 26 18:04:22 volumio volumio[1334]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Mar 26 18:04:22 volumio volumio[1334]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Mar 26 18:04:22 volumio volumio[1334]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Mar 26 18:04:22 volumio volumio[1334]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Mar 26 18:04:22 volumio volumio[1334]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Mar 26 18:04:22 volumio volumio[1334]: at Socket.emit (node:events:514:28) Mar 26 18:04:22 volumio volumio[1334]: at addChunk (node:internal/streams/readable:343:12) Mar 26 18:04:22 volumio volumio[1334]: at readableAddChunk (node:internal/streams/readable:312:11) Mar 26 18:04:22 volumio volumio[1334]: at Readable.push (node:internal/streams/readable:253:10) Mar 26 18:04:22 volumio volumio[1334]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Mar 26 18:04:22 volumio volumio[1334]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 18:04:23 volumio sudo[2658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 18:03' Mar 26 18:04:23 volumio sudo[2658]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"