Aug 29 16:47:35 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri
Aug 29 16:47:38 audio-wz volumio[1114]: info: handleBrowseUri took 2810 milliseconds
Aug 29 16:47:38 audio-wz volumio[1114]: info: Preload queue cleared
Aug 29 16:47:38 audio-wz volumio[1114]: info: Preload queue cleared
Aug 29 16:47:42 audio-wz volumio[1114]: Searching plugin music_service/qobuz
Aug 29 16:47:42 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Aug 29 16:47:43 audio-wz volumio[1114]: Searching plugin music_service/qobuz
Aug 29 16:47:43 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Aug 29 16:47:44 audio-wz volumio[1114]: Searching plugin music_service/qobuz
Aug 29 16:47:44 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Aug 29 16:47:44 audio-wz volumio[1114]: info: searchQOBUZUri took 1757 milliseconds
Aug 29 16:47:44 audio-wz volumio[1114]: info: All search sources collected, pushing search results
Aug 29 16:47:44 audio-wz volumio[1114]: info: searchQOBUZUri took 1246 milliseconds
Aug 29 16:47:44 audio-wz volumio[1114]: info: All search sources collected, pushing search results
Aug 29 16:47:45 audio-wz volumio[1114]: info: searchQOBUZUri took 1372 milliseconds
Aug 29 16:47:45 audio-wz volumio[1114]: info: All search sources collected, pushing search results
Aug 29 16:47:45 audio-wz volumio[1114]: Searching plugin music_service/qobuz
Aug 29 16:47:45 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Aug 29 16:47:46 audio-wz volumio[1114]: info: searchQOBUZUri took 1107 milliseconds
Aug 29 16:47:46 audio-wz volumio[1114]: info: All search sources collected, pushing search results
Aug 29 16:47:47 audio-wz volumio[1114]: Searching plugin music_service/qobuz
Aug 29 16:47:47 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , search
Aug 29 16:47:48 audio-wz volumio[1114]: info: searchQOBUZUri took 1079 milliseconds
Aug 29 16:47:48 audio-wz volumio[1114]: info: All search sources collected, pushing search results
Aug 29 16:47:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri
Aug 29 16:47:54 audio-wz volumio[1114]: info: handleBrowseUri took 497 milliseconds
Aug 29 16:47:54 audio-wz volumio[1114]: info: Preload queue cleared
Aug 29 16:47:54 audio-wz volumio[1114]: info: Preloading song: qobuz://song/9883170
Aug 29 16:47:54 audio-wz volumio[1114]: info: Preloading song: qobuz://song/9883171
Aug 29 16:47:54 audio-wz volumio[1114]: info: Preloading song: qobuz://song/9883172
Aug 29 16:47:54 audio-wz volumio[1114]: info: Preloading song: qobuz://song/9883173
Aug 29 16:47:54 audio-wz volumio[1114]: info: Exploding uri qobuz://song/9883170 in service qobuz
Aug 29 16:47:54 audio-wz volumio[1114]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Aug 29 16:47:54 audio-wz volumio[1114]: info: Exploding uri qobuz://song/9883171 in service qobuz
Aug 29 16:47:54 audio-wz volumio[1114]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Aug 29 16:47:55 audio-wz volumio[1114]: info: Exploding uri qobuz://song/9883172 in service qobuz
Aug 29 16:47:55 audio-wz volumio[1114]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Aug 29 16:47:55 audio-wz volumio[1114]: info: Exploding uri qobuz://song/9883173 in service qobuz
Aug 29 16:47:55 audio-wz volumio[1114]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Aug 29 16:47:55 audio-wz volumio[1114]: info: Executing endpoint getSimilarAlbums
Aug 29 16:47:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Aug 29 16:47:55 audio-wz volumio[1114]: info: Executing endpoint metavolumio
Aug 29 16:47:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Aug 29 16:47:55 audio-wz volumio[1114]: info: Executing endpoint metavolumio
Aug 29 16:47:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Aug 29 16:47:55 audio-wz volumio[1114]: info: explodeUri took 374 milliseconds
Aug 29 16:47:55 audio-wz volumio[1114]: info: explodeUri took 451 milliseconds
Aug 29 16:47:55 audio-wz volumio[1114]: info: explodeUri took 418 milliseconds
Aug 29 16:47:55 audio-wz volumio[1114]: info: explodeUri took 614 milliseconds
Aug 29 16:48:02 audio-wz volumio[1114]: info: Preload queue cleared
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreCommandRouter::volumioReplaceandPlayItems
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreStateMachine::ClearQueue
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreStateMachine::stop
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 16:48:02 audio-wz volumio[1114]: info: CorePlayQueue::clearPlayQueue
Aug 29 16:48:02 audio-wz volumio[1114]: info: CorePlayQueue::saveQueue
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushQueue
Aug 29 16:48:02 audio-wz volumio[1114]: info: CoreStateMachine::addQueueItems
Aug 29 16:48:02 audio-wz volumio[1114]: info: CorePlayQueue::addQueueItems
Aug 29 16:48:02 audio-wz volumio[1114]: info: Preload queue cleared
Aug 29 16:48:02 audio-wz volumio[1114]: info: Adding Item to queue: qobuz://album/0060253742084
Aug 29 16:48:02 audio-wz volumio[1114]: info: Exploding uri qobuz://album/0060253742084 in service qobuz
Aug 29 16:48:02 audio-wz volumio[1114]: https://prod.vlmapi.io/v2/qobuz/explodeUri
Aug 29 16:48:03 audio-wz volumio[1114]: info: explodeUri took 369 milliseconds
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushQueue
Aug 29 16:48:03 audio-wz volumio[1114]: info: CorePlayQueue::saveQueue
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::updateTrackBlock
Aug 29 16:48:03 audio-wz volumio[1114]: info: CorePlayQueue::getTrackBlock
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:03 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: play , [object Object]
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPlay
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::play index 0
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::stop
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::play index undefined
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 16:48:03 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:03 audio-wz volumio[1114]: info: CoreStateMachine::startPlaybackTimer
Aug 29 16:48:03 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:03 audio-wz volumio[1114]: info: [1788014883234] ControllerQobuz::clearAddPlayTrack
Aug 29 16:48:03 audio-wz volumio[1114]: info: getStreamUrl took 345 milliseconds
Aug 29 16:48:03 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand stop
Aug 29 16:48:03 audio-wz volumio[1114]: info: sendMpdCommand stop took 2 milliseconds
Aug 29 16:48:03 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand clear
Aug 29 16:48:03 audio-wz volumio[1114]: info:
Aug 29 16:48:03 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:03 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:03 audio-wz volumio[1114]: info: sendMpdCommand clear took 2 milliseconds
Aug 29 16:48:03 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ"
Aug 29 16:48:03 audio-wz volumio[1114]: info:
Aug 29 16:48:03 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:03 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:03 audio-wz volumio[1114]: info:
Aug 29 16:48:03 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:03 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:03 audio-wz volumio[1114]: error: updateQueue error: null
Aug 29 16:48:03 audio-wz volumio[1114]: info: ------------------------------ 8ms
Aug 29 16:48:04 audio-wz volumio[1114]: error: updateQueue error: null
Aug 29 16:48:04 audio-wz volumio[1114]: error: updateQueue error: null
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ"
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 661ms
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 659ms
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:04 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ" took 3 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand play
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:04 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces system playlist update
Aug 29 16:48:04 audio-wz volumio[1114]: info: Ignoring MPD Status Update
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 8ms
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand play took 7 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 5ms
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 3ms
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 16 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 20 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 18 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: info:
Aug 29 16:48:04 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 12 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 10 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 9 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 6 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 5 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus stop
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:04 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:04 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 90ms
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.807Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.808Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.808Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.809Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.813Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.813Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.814Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.814Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.819Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.820Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.820Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.820Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.828Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.828Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=0 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.828Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.829Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 173ms
Aug 29 16:48:04 audio-wz volumio[1114]: info: ------------------------------ 172ms
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 142 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 142 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 139 milliseconds
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:04 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:04 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:04 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:04 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:04 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:04 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.955Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.956Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.956Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.957Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.959Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.959Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.960Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.960Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.963Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.963Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.963Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.964Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.966Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.968Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.970Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.970Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.970Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.971Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.970Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.971Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.974Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.974Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=395 volume=86
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.974Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:04 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:04.975Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:05 audio-wz volumio[1114]: info: ------------------------------ 316ms
Aug 29 16:48:05 audio-wz volumio[1114]: info: ------------------------------ 315ms
Aug 29 16:48:05 audio-wz volumio[1114]: info: ------------------------------ 310ms
Aug 29 16:48:09 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume35
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.522Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.523Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.523Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.523Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio[1114]: info:
Aug 29 16:48:09 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:09 audio-wz volumio[1114]: info:
Aug 29 16:48:09 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:09 audio-wz volumio[1114]: info:
Aug 29 16:48:09 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand status took 6 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 9 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 10 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 6 milliseconds
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5991,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3152 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:09 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5991,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3157 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:09 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5991,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3157 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:09 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:09 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:09 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:09 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.651Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.651Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.652Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.653Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.657Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.657Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.658Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.659Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.660Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.661Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.661Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.661Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.665Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.665Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.666Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.666Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.671Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.672Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.672Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.672Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.675Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.676Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=4942 volume=35
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.677Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:09.678Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:09 audio-wz volumio[1114]: info: ------------------------------ 188ms
Aug 29 16:48:09 audio-wz volumio[1114]: info: ------------------------------ 187ms
Aug 29 16:48:09 audio-wz volumio[1114]: info: ------------------------------ 187ms
Aug 29 16:48:10 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume34
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:10 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:10.932Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:10 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:10.932Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:10 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:10.932Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:10 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:10.933Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:10 audio-wz volumio[1114]: info:
Aug 29 16:48:10 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:10 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:10 audio-wz volumio[1114]: info:
Aug 29 16:48:10 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:10 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:10 audio-wz volumio[1114]: info:
Aug 29 16:48:10 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:10 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:10 audio-wz volumio[1114]: info: sendMpdCommand status took 6 milliseconds
Aug 29 16:48:10 audio-wz volumio[1114]: info: sendMpdCommand status took 2 milliseconds
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:10 audio-wz volumio[1114]: info: sendMpdCommand status took 15 milliseconds
Aug 29 16:48:10 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 13 milliseconds
Aug 29 16:48:10 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 13 milliseconds
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:10 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7364,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3226 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:10 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:10 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7490,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3209 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:10 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:10 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:10 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:10 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.023Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.023Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.024Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.024Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.028Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.030Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.031Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.032Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.036Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.036Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.037Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.037Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.043Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.043Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6259 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.044Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.044Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 153ms
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 150ms
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 139 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7490,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3269 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:11 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.137Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6620 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.138Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6620 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.138Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.138Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.142Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6620 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.142Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6620 volume=34
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.143Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.143Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 216ms
Aug 29 16:48:11 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume24
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.266Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.267Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.267Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.268Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio[1114]: info:
Aug 29 16:48:11 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:11 audio-wz volumio[1114]: info:
Aug 29 16:48:11 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:11 audio-wz volumio[1114]: info:
Aug 29 16:48:11 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 3 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7743,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3213 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:11 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.329Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.330Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.331Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.332Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.333Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.334Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6620 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.334Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.335Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 63ms
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 57 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 58 milliseconds
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7743,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3276 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:11 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7743,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3276 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:11 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:11 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:11 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:11 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.404Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.404Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.405Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.405Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.408Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.409Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.409Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.410Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.412Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.412Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.413Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.413Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.415Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.416Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=6876 volume=24
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.417Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:11.417Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 157ms
Aug 29 16:48:11 audio-wz volumio[1114]: info: ------------------------------ 157ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume25
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.343Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8627 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.344Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8627 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.344Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.345Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 5 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 4 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":9868,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3142 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":9868,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3133 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":9868,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3133 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.452Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.452Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.453Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.453Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.457Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.457Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.458Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.459Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.461Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.461Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.462Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.463Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.468Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.469Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.469Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.470Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.474Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.474Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.475Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.475Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.478Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.480Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=8893 volume=25
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.482Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.483Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 168ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 167ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 166ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume42
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.747Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.748Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.748Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.749Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info:
Aug 29 16:48:13 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 3 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10242,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3126 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.815Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.816Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.816Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.818Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.820Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.821Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.821Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.822Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 73ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 69 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 70 milliseconds
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10242,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3163 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10242,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3163 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:13 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:13 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:13 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:13 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.891Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.892Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.892Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.893Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.895Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.896Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.896Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.897Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.899Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.899Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.900Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.901Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.902Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.903Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=42
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.903Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:13.903Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 160ms
Aug 29 16:48:13 audio-wz volumio[1114]: info: ------------------------------ 160ms
Aug 29 16:48:14 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume43
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.047Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9142 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.048Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9142 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.048Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.048Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio[1114]: info:
Aug 29 16:48:14 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:14 audio-wz volumio[1114]: info:
Aug 29 16:48:14 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:14 audio-wz volumio[1114]: info:
Aug 29 16:48:14 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand status took 25 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 2 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 2 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 2 milliseconds
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10494,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3090 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:14 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10615,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3141 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:14 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10615,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3102 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:14 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:14 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:14 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:14 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.132Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.134Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.134Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.135Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.135Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.136Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.136Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.137Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.138Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.138Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.138Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.139Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.139Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.140Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.141Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.141Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.141Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=9579 volume=43
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.141Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:14.141Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:14 audio-wz volumio[1114]: info: ------------------------------ 87ms
Aug 29 16:48:14 audio-wz volumio[1114]: info: ------------------------------ 66ms
Aug 29 16:48:14 audio-wz volumio[1114]: info: ------------------------------ 65ms
Aug 29 16:48:15 audio-wz volumio[1114]: info: VolumeController::SetAlsaVolume45
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.191Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.192Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.193Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.193Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio[1114]: info:
Aug 29 16:48:15 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:15 audio-wz volumio[1114]: info:
Aug 29 16:48:15 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:15 audio-wz volumio[1114]: info:
Aug 29 16:48:15 audio-wz volumio[1114]: ---------------------------- MPD announces state update: mixer
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand status took 4 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 1 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 2 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11741,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3137 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:15 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11741,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3184 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:15 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.238Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.239Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.239Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.239Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.239Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.240Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.240Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.240Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.239Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.241Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.242Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio[1114]: info: ------------------------------ 42ms
Aug 29 16:48:15 audio-wz volumio[1114]: info: ------------------------------ 41ms
Aug 29 16:48:15 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 36 milliseconds
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:15 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11741,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3184 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:15 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService play
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus play
Aug 29 16:48:15 audio-wz volumio[1114]: info: Received an update from plugin. extracting info from payload
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:15 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:15 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.262Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.262Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.262Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.263Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PLAYING positionMs=10580 volume=45
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.263Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.263Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.263Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:15.263Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:15 audio-wz volumio[1114]: info: ------------------------------ 55ms
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::stPlaybackTimer
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::servicePause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::servicePause
Aug 29 16:48:21 audio-wz volumio[1114]: info: [1788014901772] ControllerQobuz::pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::pause
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand pause
Aug 29 16:48:21 audio-wz volumio[1114]: info:
Aug 29 16:48:21 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand pause took 4 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:21 audio-wz volumio[1114]: info:
Aug 29 16:48:21 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:21 audio-wz volumio[1114]: info:
Aug 29 16:48:21 audio-wz volumio[1114]: ---------------------------- MPD announces state update: player
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::getState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand status took 2 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand status took 3 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseState
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 4 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 4 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: info: sendMpdCommand playlistinfo took 1 milliseconds
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: ControllerMpd::parseTrackInfo
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":18243,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3106 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::stPlaybackTimer
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":18243,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3106 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::stPlaybackTimer
Aug 29 16:48:21 audio-wz volumio[1114]: info: ControllerMpd::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::servicePushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CorePlayQueue::getTrack 0
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":18243,"duration":463,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3106 Kbps","isStreaming":false,"title":"file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=1926692&eid=9883170&fmt=7&profile=raw&app_id=539451548&cid=3819539&etsp=1788018483&hmac=T3LpUW1FG2irBVTW79Bf2ByufwQ","trackType":"qobuz"}
Aug 29 16:48:21 audio-wz volumio[1114]: verbose: CURRENT POSITION 0
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState stateService pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::syncState currentStatus pause
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:21 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:21 audio-wz volumio[1114]: info: CoreStateMachine::stPlaybackTimer
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.804Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.805Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.806Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.807Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.807Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.807Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.807Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.807Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.810Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.810Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PAUSED positionMs=17089 volume=45
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.811Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:21.811Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:21 audio-wz volumio[1114]: info: ------------------------------ 36ms
Aug 29 16:48:21 audio-wz volumio[1114]: info: ------------------------------ 36ms
Aug 29 16:48:21 audio-wz volumio[1114]: info: ------------------------------ 35ms
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Aug 29 16:48:32 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Aug 29 16:48:44 audio-wz systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Aug 29 16:48:46 audio-wz systemd[1]: setdatetime-helper.service: Deactivated successfully.
Aug 29 16:48:46 audio-wz systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Aug 29 16:48:46 audio-wz systemd[1]: setdatetime-helper.service: Consumed 1.000s CPU time.
Aug 29 16:48:53 audio-wz volumio[1114]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object]
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions
Aug 29 16:48:53 audio-wz volumio[1114]: info: Preparing to save Alsa Options, stopping services first
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPause
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreStateMachine::pause
Aug 29 16:48:53 audio-wz volumio[1114]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":true,"i2sid":{"value":"hifiberry-dac2hd","label":"HiFiBerry DAC2 HD"}}
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: Enabling I2S DAC: HiFiBerry DAC2 HD
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz sudo[6191]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l
Aug 29 16:48:53 audio-wz sudo[6191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:53 audio-wz sudo[6191]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:53 audio-wz volumio[1114]: info: No Overlays Loaded
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz sudo[6194]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dacplushd
Aug 29 16:48:53 audio-wz sudo[6194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:53 audio-wz volumio[1114]: warn: Unable to locate the device HDMI Out a reboot may be required.
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2c@7e804000/status
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/clocks
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/reset-gpio
Aug 29 16:48:53 audio-wz kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status
Aug 29 16:48:53 audio-wz sudo[6194]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: Found match in i2s Card Database: setting mixer DAC for card HiFiBerry DAC2 HD
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::volumioUpdateVolumeSettings
Aug 29 16:48:53 audio-wz volumio[1114]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC2 HD Mixer: DAC Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume
Aug 29 16:48:53 audio-wz volumio[1114]: info: Disabling external Volume Control
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction
Aug 29 16:48:53 audio-wz volumio[1114]: info: Preparing to generate the ALSA configuration file
Aug 29 16:48:53 audio-wz kernel: pcm179x 1-004c: No cache used with register defaults set!
Aug 29 16:48:53 audio-wz volumio[1114]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Aug 29 16:48:53 audio-wz volumio[1114]: info: Reading ALSA contributions from plugins.
Aug 29 16:48:53 audio-wz volumio[1114]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'DAC',0
Aug 29 16:48:53 audio-wz volumio[1114]: info: I2S Param [object Object] successfully enabled
Aug 29 16:48:53 audio-wz kernel: snd-rpi-hifiberry-dacplushd soc:sound: ASoC: driver name too long 'HifiberryDacplusHD' -> 'HifiberryDacplu'
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Aug 29 16:48:53 audio-wz volumio[1114]: info: Getting Alsa Cards List without I2S DAC
Aug 29 16:48:53 audio-wz (udev-worker)[6209]: controlC3: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 3' failed with exit code 99.
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Aug 29 16:48:53 audio-wz volumio[1114]: info: VolumeController:: Volume=undefined Mute =false
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreStateMachine::pushState
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::volumioPushState
Aug 29 16:48:53 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output update for this device
Aug 29 16:48:53 audio-wz volumio[1114]: info: MRS: Pushing multiroomSync output
Aug 29 16:48:53 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:53 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:53.945Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" state=STATUS_PAUSED positionMs=17344 volume=45
Aug 29 16:48:53 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:53.945Z level=INFO msg="emitting player state changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" state=STATUS_PAUSED positionMs=17344 volume=45
Aug 29 16:48:53 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:53.946Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.178.98:43758 @ 0x32f0de0" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:53 audio-wz volumio5-onboarding[1662]: time=2026-08-29T14:48:53.946Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.98:43758 @ 0x3421350" id=qobuz://song/9883170 title="A Love Supreme, Pt. I – Acknowledgement (Album Version)"
Aug 29 16:48:53 audio-wz volumio[1114]: info: Asound.conf file written
Aug 29 16:48:53 audio-wz sudo[6272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Aug 29 16:48:53 audio-wz sudo[6272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6272]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card b1
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: /usr/share/alsa/init/bcm2835:14: control element not found
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card b1
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card Headphones
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: /usr/share/alsa/init/bcm2835:20: control element not found
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card Headphones
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card vc4hdmi
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: Found hardware: "vc4-hdmi" "" "" "" ""
Aug 29 16:48:54 audio-wz volumio[1114]: Hardware is initialized using a generic method
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card vc4hdmi
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card sndrpihifiberry
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: Found hardware: "HifiberryDacplu" "" "" "" ""
Aug 29 16:48:54 audio-wz volumio[1114]: Hardware is initialized using a generic method
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card sndrpihifiberry
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting MPD
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting Shairport Sync
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:54 audio-wz sudo[6280]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 29 16:48:54 audio-wz sudo[6280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6280]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 29 16:48:54 audio-wz volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 29 16:48:54 audio-wz volumio[1114]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Aug 29 16:48:54 audio-wz sudo[6285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: QobuzConnect: setDeactiveState invoked
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting MPD
Aug 29 16:48:54 audio-wz sudo[6293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:54 audio-wz sudo[6293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz systemd[1]: Stopping mpd.service - Music Player Daemon...
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting Shairport Sync
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:54 audio-wz sudo[6295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 29 16:48:54 audio-wz sudo[6295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6295]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 29 16:48:54 audio-wz sudo[6300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6293]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 29 16:48:54 audio-wz volumio[1114]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: QobuzConnect: setDeactiveState invoked
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:54 audio-wz systemd[1]: mpd.service: Deactivated successfully.
Aug 29 16:48:54 audio-wz systemd[1]: Stopped mpd.service - Music Player Daemon.
Aug 29 16:48:54 audio-wz systemd[1]: mpd.service: Consumed 23.021s CPU time.
Aug 29 16:48:54 audio-wz sudo[6309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:54 audio-wz sudo[6309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz systemd[1]: mpd.socket: Deactivated successfully.
Aug 29 16:48:54 audio-wz systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Aug 29 16:48:54 audio-wz systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Aug 29 16:48:54 audio-wz sudo[6311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:54 audio-wz sudo[6311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:54 audio-wz sudo[6315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Aug 29 16:48:54 audio-wz systemd[1]: Starting mpd.service - Music Player Daemon...
Aug 29 16:48:54 audio-wz sudo[6324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Aug 29 16:48:54 audio-wz sudo[6324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6309]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz volumio[1114]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split')
Aug 29 16:48:54 audio-wz volumio[1114]: info: MPD Permissions set
Aug 29 16:48:54 audio-wz volumio[1114]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split')
Aug 29 16:48:54 audio-wz sudo[6331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Aug 29 16:48:54 audio-wz volumio[1114]: info: MPD Permissions set
Aug 29 16:48:54 audio-wz sudo[6331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6311]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6324]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6331]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz sudo[6335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Aug 29 16:48:54 audio-wz sudo[6335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz sudo[6315]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6322]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Aug 29 16:48:54 audio-wz sudo[6322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 29 16:48:54 audio-wz sudo[6338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Aug 29 16:48:54 audio-wz sudo[6338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Aug 29 16:48:54 audio-wz sudo[6322]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz qobuz-connect[3627]: 20260829 16:48:54.656 [3627.3627] INFO SampleApp: Stopping Local configuration server
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: Starting Shairport Sync
Aug 29 16:48:54 audio-wz volumio[1114]: info: Starting Shairport Sync
Aug 29 16:48:54 audio-wz volumio[1114]: info: Preparing to generate the ALSA configuration file
Aug 29 16:48:54 audio-wz sudo[6355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 29 16:48:54 audio-wz sudo[6355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6357]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 29 16:48:54 audio-wz sudo[6357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz volumio[1114]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Aug 29 16:48:54 audio-wz volumio[1114]: info: Reading ALSA contributions from plugins.
Aug 29 16:48:54 audio-wz volumio[1114]: info: Asound.conf file written
Aug 29 16:48:54 audio-wz sudo[6362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Aug 29 16:48:54 audio-wz sudo[6362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz sudo[6362]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Aug 29 16:48:54 audio-wz systemd[1]: shairport-sync.service: Deactivated successfully.
Aug 29 16:48:54 audio-wz systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 29 16:48:54 audio-wz systemd[1]: shairport-sync.service: Consumed 6.612s CPU time.
Aug 29 16:48:54 audio-wz systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 29 16:48:54 audio-wz sudo[6355]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6357]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card b1
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: /usr/share/alsa/init/bcm2835:14: control element not found
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card b1
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card Headphones
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: /usr/share/alsa/init/bcm2835:20: control element not found
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card Headphones
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card vc4hdmi
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: Found hardware: "vc4-hdmi" "" "" "" ""
Aug 29 16:48:54 audio-wz volumio[1114]: Hardware is initialized using a generic method
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card vc4hdmi
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card sndrpihifiberry
Aug 29 16:48:54 audio-wz volumio[1114]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2
Aug 29 16:48:54 audio-wz volumio[1114]: Found hardware: "HifiberryDacplu" "" "" "" ""
Aug 29 16:48:54 audio-wz volumio[1114]: Hardware is initialized using a generic method
Aug 29 16:48:54 audio-wz volumio[1114]: No state is present for card sndrpihifiberry
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting MPD
Aug 29 16:48:54 audio-wz sudo[6369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 29 16:48:54 audio-wz sudo[6369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:54 audio-wz volumio[1114]: info: Output device has changed, restarting Shairport Sync
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:54 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:54 audio-wz sudo[6369]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:54 audio-wz sudo[6384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 29 16:48:54 audio-wz sudo[6384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 29 16:48:55 audio-wz volumio[1114]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: QobuzConnect: setDeactiveState invoked
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:55 audio-wz systemd[1]: mpd.service: Deactivated successfully.
Aug 29 16:48:55 audio-wz systemd[1]: Stopped mpd.service - Music Player Daemon.
Aug 29 16:48:55 audio-wz systemd[1]: mpd.socket: Deactivated successfully.
Aug 29 16:48:55 audio-wz systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Aug 29 16:48:55 audio-wz systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Aug 29 16:48:55 audio-wz volumio[1114]: info: Preparing to generate the ALSA configuration file
Aug 29 16:48:55 audio-wz sudo[6396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:55 audio-wz sudo[6396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz sudo[6399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:55 audio-wz systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Aug 29 16:48:55 audio-wz sudo[6399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz systemd[1]: Starting mpd.service - Music Player Daemon...
Aug 29 16:48:55 audio-wz sudo[6407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Aug 29 16:48:55 audio-wz sudo[6407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz volumio[1114]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Aug 29 16:48:55 audio-wz volumio[1114]: info: Reading ALSA contributions from plugins.
Aug 29 16:48:55 audio-wz volumio[1114]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split')
Aug 29 16:48:55 audio-wz volumio[1114]: info: MPD Permissions set
Aug 29 16:48:55 audio-wz volumio[1114]: info: Shairport-Sync Started
Aug 29 16:48:55 audio-wz volumio[1114]: info: Shairport-Sync Started
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:55 audio-wz volumio[1114]: info: Starting Shairport Sync
Aug 29 16:48:55 audio-wz sudo[6407]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:55 audio-wz sudo[6399]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:55 audio-wz sudo[6396]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:55 audio-wz volumio[1114]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________
Aug 29 16:48:55 audio-wz volumio[1114]: info: PLUGIN onReboot : networkfs
Aug 29 16:48:55 audio-wz sudo[6415]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Aug 29 16:48:55 audio-wz sudo[6415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz sudo[6418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 29 16:48:55 audio-wz sudo[6418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz sudo[6405]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Aug 29 16:48:55 audio-wz sudo[6424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Medien
Aug 29 16:48:55 audio-wz sudo[6405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 29 16:48:55 audio-wz sudo[6424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:55 audio-wz sudo[6405]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:55 audio-wz systemd[1]: mnt-NAS-Medien.mount: Deactivated successfully.
Aug 29 16:48:55 audio-wz systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Aug 29 16:48:55 audio-wz systemd[1]: shairport-sync.service: Deactivated successfully.
Aug 29 16:48:55 audio-wz systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 29 16:48:55 audio-wz systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Aug 29 16:48:55 audio-wz sudo[6418]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6424]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz qobuz-connect[3627]: 20260829 16:48:56.021 [3627.3627] INFO SampleApp: shat down connection on UNIX socket
Aug 29 16:48:56 audio-wz systemd[1]: qobuz-connect.service: Deactivated successfully.
Aug 29 16:48:56 audio-wz systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service.
Aug 29 16:48:56 audio-wz systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Aug 29 16:48:56 audio-wz sudo[6415]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6338]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6335]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz volumio[1114]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected
Aug 29 16:48:56 audio-wz volumio[1114]: info: QobuzConnect: setDeactiveState invoked
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:56 audio-wz volumio[1114]: info: Shairport-Sync Started
Aug 29 16:48:56 audio-wz volumio[1114]: info: Asound.conf file unchanged, so no further update is needed
Aug 29 16:48:56 audio-wz volumio[1114]: info: Output device has changed, restarting MPD
Aug 29 16:48:56 audio-wz sudo[6448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reboot
Aug 29 16:48:56 audio-wz sudo[6448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz volumio[1114]: info: Output device has changed, restarting Shairport Sync
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:56 audio-wz sudo[6451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Aug 29 16:48:56 audio-wz sudo[6451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz sudo[6453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Aug 29 16:48:56 audio-wz sudo[6453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz sudo[6451]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz systemd-logind[699]: The system will reboot now!
Aug 29 16:48:56 audio-wz volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Aug 29 16:48:56 audio-wz volumio[1114]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:56 audio-wz volumio[1114]: info: QobuzConnect: setDeactiveState invoked
Aug 29 16:48:56 audio-wz systemd-logind[699]: System is rebooting.
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::volumioGetState
Aug 29 16:48:56 audio-wz sudo[6463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:56 audio-wz sudo[6463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz sudo[6285]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6300]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6384]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Aug 29 16:48:56 audio-wz sudo[6465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz sudo[6448]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:56 audio-wz sudo[6473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Aug 29 16:48:56 audio-wz sudo[6473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:56 audio-wz volumio[1114]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split')
Aug 29 16:48:56 audio-wz volumio[1114]: info: MPD Permissions set
Aug 29 16:48:56 audio-wz volumio[1114]: info: Rebooting
Aug 29 16:48:56 audio-wz volumio[1114]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service
Aug 29 16:48:56 audio-wz volumio[1114]: Job for mpd.service canceled.
Aug 29 16:48:56 audio-wz volumio[1114]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service
Aug 29 16:48:56 audio-wz volumio[1114]: Job for mpd.service canceled.
Aug 29 16:48:56 audio-wz volumio[1114]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service
Aug 29 16:48:56 audio-wz volumio[1114]: Job for mpd.service canceled.
Aug 29 16:48:56 audio-wz systemd[1]: Requested transaction contradicts existing jobs: Transaction for mpd.service/restart is destructive (systemd-remount-fs.service has 'stop' job queued, but 'start' is included in transaction).
Aug 29 16:48:56 audio-wz volumio[1114]: info: Executing endpoint qc_getconfig
Aug 29 16:48:56 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Aug 29 16:48:56 audio-wz sudo[6453]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz sudo[6473]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz systemd[1]: Removed slice system-modprobe.slice - Slice /system/modprobe.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target bluetooth.target - Bluetooth Support.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target graphical.target - Graphical Interface.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target rpc_pipefs.target.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target rpcbind.target - RPC Port Mapper.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped target timers.target - Timer Units.
Aug 29 16:48:57 audio-wz systemd[1]: apt-daily-upgrade.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped apt-daily-upgrade.timer - Daily apt upgrade and clean activities.
Aug 29 16:48:57 audio-wz systemd[1]: apt-daily.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped apt-daily.timer - Daily apt download activities.
Aug 29 16:48:57 audio-wz systemd[1]: dpkg-db-backup.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped dpkg-db-backup.timer - Daily dpkg database backup timer.
Aug 29 16:48:57 audio-wz systemd[1]: e2scrub_all.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems.
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.076 [6446.6446] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Aug 29 16:48:57 audio-wz systemd[1]: fstrim.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.082 [6446.6446] INFO VolumeManager: [0x1e57f68]: Setting new playback volume: 75
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.082 [6446.6446] INFO VolumeManager: [0x1e57f68]: Setting new mute state: 0
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.082 [6446.6446] INFO AudioStreamManager: [0x1e57cc0]: Setting new audio download buffer size: 1048576
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.082 [6446.6446] INFO QobuzConnect: [0x1e58830]: Client initialized!
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.082 [6446.6446] INFO SampleApp: Starting Avahi advertising, name: audio-wz, service name: _qobuz-connect._tcp
Aug 29 16:48:57 audio-wz systemd[1]: Stopped fstrim.timer - Discard unused blocks once a week.
Aug 29 16:48:57 audio-wz systemd[1]: ntpsec-rotate-stats.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped ntpsec-rotate-stats.timer - Rotate ntpd stats daily.
Aug 29 16:48:57 audio-wz systemd[1]: setdatetime-helper.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped setdatetime-helper.timer - Volumio Time Sync Watchdog Timer.
Aug 29 16:48:57 audio-wz systemd[1]: systemd-tmpfiles-clean.timer: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories.
Aug 29 16:48:57 audio-wz systemd[1]: systemd-rfkill.socket: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Closed systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch.
Aug 29 16:48:57 audio-wz volumio[1114]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Aug 29 16:48:57 audio-wz volumio[1114]: info: QobuzConnect: QOBUZ Connect daemon connected
Aug 29 16:48:57 audio-wz volumio[1114]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service
Aug 29 16:48:57 audio-wz volumio[1114]: Failed to restart mpd.service: Transaction for mpd.service/restart is destructive (systemd-remount-fs.service has 'stop' job queued, but 'start' is included in transaction).
Aug 29 16:48:57 audio-wz volumio[1114]: See system logs and 'systemctl status mpd.service' for details.
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz sudo[6479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Aug 29 16:48:57 audio-wz sudo[6479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.153 [6446.6446] INFO LocalConfigManager: [0x1e579e8]: Starting Local Configuration server
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.153 [6446.6446] INFO SampleApp: Starting Local configuration server
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.154 [6446.6446] INFO SampleApp: Connected to UNIX socket client 0x1e42818
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Aug 29 16:48:57 audio-wz systemd[1]: Unmounting run-rpc_pipefs.mount - RPC Pipe File System...
Aug 29 16:48:57 audio-wz bluealsa[961]: ../src/ba-adapter.c:144: Freeing adapter: hci0
Aug 29 16:48:57 audio-wz systemd[1]: Stopping bluealsa.service - BlueALSA service...
Aug 29 16:48:57 audio-wz volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Aug 29 16:48:57 audio-wz bluetoothd[891]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/1
Aug 29 16:48:57 audio-wz bluetoothd[891]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/2
Aug 29 16:48:57 audio-wz systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service...
Aug 29 16:48:57 audio-wz systemd[1]: rpi-display-backlight.service - Turns off Raspberry Pi display backlight on shutdown/reboot was skipped because of an unmet condition check (ConditionPathIsDirectory=/proc/device-tree/rpi_backlight).
Aug 29 16:48:57 audio-wz sshd[1525]: Received signal 15; terminating.
Aug 29 16:48:57 audio-wz bluetoothd[891]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/2
Aug 29 16:48:57 audio-wz qobuz-connect[6446]: 20260829 16:48:57.196 [6446.6446] INFO SampleApp: Stopping Local configuration server
Aug 29 16:48:57 audio-wz bluetoothd[891]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/1
Aug 29 16:48:57 audio-wz systemd[1]: Stopping ssh.service - OpenBSD Secure Shell server...
Aug 29 16:48:57 audio-wz systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Aug 29 16:48:57 audio-wz autossh[3493]: received signal to exit (15)
Aug 29 16:48:57 audio-wz volumio[1114]: info: Starting Shairport Sync
Aug 29 16:48:57 audio-wz systemd[1]: Stopping systemd-random-seed.service - Load/Save Random Seed...
Aug 29 16:48:57 audio-wz systemd[1]: Stopping volumio5-onboarding.service - Volumio5 Onboarding Server...
Aug 29 16:48:57 audio-wz systemd[1]: Stopping volumiobt.service - Volumio Bluetooth Module...
Aug 29 16:48:57 audio-wz volumio[1114]: info: TidalConnect service stoped!
Aug 29 16:48:57 audio-wz volumiobt[6494]: INFO [BTSTART] Disconnecting all Bluetooth devices...
Aug 29 16:48:57 audio-wz sudo[6493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Aug 29 16:48:57 audio-wz sudo[6493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 16:48:57 audio-wz systemd[1]: bluealsa.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped bluealsa.service - BlueALSA service.
Aug 29 16:48:57 audio-wz systemd[1]: ssh.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped ssh.service - OpenBSD Secure Shell server.
Aug 29 16:48:57 audio-wz systemd[1]: volumio5-onboarding.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Aug 29 16:48:57 audio-wz systemd[1]: volumio5-onboarding.service: Consumed 7.258s CPU time.
Aug 29 16:48:57 audio-wz systemd[1]: sshtunnel.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Aug 29 16:48:57 audio-wz systemd[1]: mpd.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped mpd.service - Music Player Daemon.
Aug 29 16:48:57 audio-wz systemd[1]: mpd.service: Consumed 1.343s CPU time.
Aug 29 16:48:57 audio-wz systemd[1]: run-rpc_pipefs.mount: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Unmounted run-rpc_pipefs.mount - RPC Pipe File System.
Aug 29 16:48:57 audio-wz systemd[1]: systemd-random-seed.service: Deactivated successfully.
Aug 29 16:48:57 audio-wz systemd[1]: Stopped systemd-random-seed.service - Load/Save Random Seed.
Aug 29 16:48:57 audio-wz bluetoothd[891]: Adv Monitor app :1.86 disconnected from D-Bus
Aug 29 16:48:57 audio-wz sudo[6463]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz volumio[1114]: info: TidalConnect service stoped!
Aug 29 16:48:57 audio-wz volumiobt[6502]: Attempting to disconnect from 41:AE:FF:0E:65:08
Aug 29 16:48:57 audio-wz volumiobt[6502]: [NEW] Media /org/bluez/hci0
Aug 29 16:48:57 audio-wz volumiobt[6502]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Aug 29 16:48:57 audio-wz volumiobt[6502]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Aug 29 16:48:57 audio-wz volumiobt[6502]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Aug 29 16:48:57 audio-wz bluetoothd[891]: Path / reserved for Adv Monitor app :1.87
Aug 29 16:48:57 audio-wz volumiobt[6502]: AdvertisementMonitor path registered
Aug 29 16:48:57 audio-wz systemd[1]: Requested transaction contradicts existing jobs: Transaction for qobuz-connect.service/restart is destructive (proc-sys-fs-binfmt_misc.automount has 'stop' job queued, but 'start' is included in transaction).
Aug 29 16:48:57 audio-wz sudo[6479]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz sudo[6465]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz volumio[1114]: info: TidalConnect service stoped!
Aug 29 16:48:57 audio-wz systemd[1]: Requested transaction contradicts existing jobs: Transaction for shairport-sync.service/restart is destructive (var-log.mount has 'stop' job queued, but 'start' is included in transaction).
Aug 29 16:48:57 audio-wz sudo[6493]: pam_unix(sudo:session): session closed for user root
Aug 29 16:48:57 audio-wz volumio[1114]: error: QobuzConnect: could not execute /bin/systemctl to restart qobuz connect process. Reason: Failed to restart qobuz-connect.service: Transaction for qobuz-connect.service/restart is destructive (proc-sys-fs-binfmt_misc.automount has 'stop' job queued, but 'start' is included in transaction).
Aug 29 16:48:57 audio-wz volumio[1114]: See system logs and 'systemctl status qobuz-connect.service' for details.
Aug 29 16:48:57 audio-wz volumio[1114]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 16:48:57 audio-wz volumio[1114]: [UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "undefined".] {
Aug 29 16:48:57 audio-wz volumio[1114]: code: 'ERR_UNHANDLED_REJECTION'
Aug 29 16:48:57 audio-wz volumio[1114]: }
Aug 29 16:48:57 audio-wz volumio[1114]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 16:48:58 audio-wz sudo[6523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 16:47'
Aug 29 16:48:58 audio-wz sudo[6523]: 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"