-- Logs begin at Thu 2025-05-01 12:25:07 UTC, end at Thu 2025-05-15 13:34:16 UTC. -- May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 13:33:23 mx-stream volumio[1010]: info: Discovery: Getting this device information May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::volumioGetState May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedPAddresses May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getConf May 15 13:33:23 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getConf May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::volumioNext May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:33:50 mx-stream volumio[1010]: info: [1747316030449] ControllerQobuz::next May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::stop May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:33:50 mx-stream volumio[1010]: verbose: UNSET VOLATILE May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 4 May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::serviceStop May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 4 May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::serviceStop May 15 13:33:50 mx-stream volumio[1010]: info: [1747316030455] ControllerQobuz::stop May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:33:50 mx-stream volumio[1010]: info: ControllerMpd::stop May 15 13:33:50 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:33:50 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:33:50 mx-stream volumio[1010]: info: sendMpdCommand stop took 395 milliseconds May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::play index undefined May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::startPlaybackTimer May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:50 mx-stream volumio[1010]: info: [1747316030852] ControllerQobuz::clearAddPlayTrack May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:33:50 mx-stream volumio[1010]: info: May 15 13:33:50 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:33:50 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:33:50 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:33:50 mx-stream volumio[1010]: info: sendMpdCommand status took 9 milliseconds May 15 13:33:50 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:33:50 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:33:50 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 13:33:50 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:33:50 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:33:50 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:33:50 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:33:50 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:50 mx-stream volumio[1010]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 15 13:33:50 mx-stream volumio[1010]: info: ------------------------------ 26ms May 15 13:33:50 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:33:51 mx-stream volumio[1010]: info: getStreamUrl took 494 milliseconds May 15 13:33:51 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:33:51 mx-stream volumio[1010]: info: sendMpdCommand stop took 2 milliseconds May 15 13:33:51 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand clear May 15 13:33:51 mx-stream volumio[1010]: info: May 15 13:33:51 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:33:51 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:33:51 mx-stream volumio[1010]: info: sendMpdCommand clear took 1 milliseconds May 15 13:33:51 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8" May 15 13:33:51 mx-stream volumio[1010]: error: updateQueue error: null May 15 13:33:51 mx-stream volumio[1010]: info: ------------------------------ 3ms May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8" May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8" took 1 milliseconds May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand play May 15 13:33:52 mx-stream volumio[1010]: info: May 15 13:33:52 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:33:52 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand play took 4 milliseconds May 15 13:33:52 mx-stream volumio[1010]: info: ------------------------------ 3ms May 15 13:33:52 mx-stream volumio[1010]: info: May 15 13:33:52 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:33:52 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand status took 3 milliseconds May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:33:52 mx-stream volumio[1010]: info: May 15 13:33:52 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:33:52 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 5 milliseconds May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand status took 3 milliseconds May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:33:52 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:33:52 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:52 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":179,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8","trackType":"qobuz"} May 15 13:33:52 mx-stream volumio[1010]: verbose: CURRENT POSITION 5 May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus stop May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:33:52 mx-stream volumio[1010]: info: ------------------------------ 35ms May 15 13:33:52 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 23 milliseconds May 15 13:33:52 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:33:52 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:33:52 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:33:52 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":179,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"650 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334117&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319631&hmac=Rjtp0a5flj0Egaf2_3iy_aLchK8","trackType":"qobuz"} May 15 13:33:52 mx-stream volumio[1010]: verbose: CURRENT POSITION 5 May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus play May 15 13:33:52 mx-stream volumio[1010]: info: Received an update from plugin. extracting info from payload May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:33:52 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:33:52 mx-stream volumio[1010]: info: ------------------------------ 47ms May 15 13:33:52 mx-stream volumio[1010]: info: Updating push state because input changed May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::volumiosetSourceActivempd May 15 13:33:52 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 13:33:52 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:33:52 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:33:52 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 13:33:53 mx-stream volumio[1010]: info: Discovery: Getting this device information May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::volumioGetState May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedPAddresses May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getConf May 15 13:33:53 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: system , getConf May 15 13:34:02 mx-stream volumio[1010]: info: CoreCommandRouter::volumioRandom May 15 13:34:02 mx-stream volumio[1010]: info: CoreCommandRouter::writePlayerControls May 15 13:34:02 mx-stream volumio[1010]: info: CoreStateMachine::setRandom true May 15 13:34:02 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:02 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:02 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:02 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::volumioNext May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:34:03 mx-stream volumio[1010]: info: [1747316043434] ControllerQobuz::next May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::stop May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:03 mx-stream volumio[1010]: verbose: UNSET VOLATILE May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::serviceStop May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 5 May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::serviceStop May 15 13:34:03 mx-stream volumio[1010]: info: [1747316043441] ControllerQobuz::stop May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:03 mx-stream volumio[1010]: info: ControllerMpd::stop May 15 13:34:03 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:34:03 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:03 mx-stream volumio[1010]: info: sendMpdCommand stop took 161 milliseconds May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::play index undefined May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::startPlaybackTimer May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:03 mx-stream volumio[1010]: info: [1747316043605] ControllerQobuz::clearAddPlayTrack May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:34:03 mx-stream volumio[1010]: info: May 15 13:34:03 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:03 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:03 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:03 mx-stream volumio[1010]: info: sendMpdCommand status took 6 milliseconds May 15 13:34:03 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:03 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:03 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 13:34:03 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:03 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:03 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:03 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:03 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:03 mx-stream volumio[1010]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 15 13:34:03 mx-stream volumio[1010]: info: ------------------------------ 24ms May 15 13:34:03 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:04 mx-stream volumio[1010]: info: getStreamUrl took 493 milliseconds May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand stop took 1 milliseconds May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand clear May 15 13:34:04 mx-stream volumio[1010]: info: May 15 13:34:04 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:04 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand clear took 2 milliseconds May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4" May 15 13:34:04 mx-stream volumio[1010]: error: updateQueue error: null May 15 13:34:04 mx-stream volumio[1010]: info: ------------------------------ 4ms May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4" May 15 13:34:04 mx-stream volumio[1010]: info: May 15 13:34:04 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:04 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4" took 7 milliseconds May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand play May 15 13:34:04 mx-stream volumio[1010]: info: ------------------------------ 3ms May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand play took 3 milliseconds May 15 13:34:04 mx-stream volumio[1010]: info: May 15 13:34:04 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:04 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:04 mx-stream volumio[1010]: info: May 15 13:34:04 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:04 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand status took 7 milliseconds May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand status took 8 milliseconds May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 9 milliseconds May 15 13:34:04 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 8 milliseconds May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:04 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:04 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:04 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:04 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":206,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"768 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4","trackType":"qobuz"} May 15 13:34:04 mx-stream volumio[1010]: verbose: CURRENT POSITION 3 May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus stop May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:04 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:04 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:04 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":206,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"768 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334115&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319643&hmac=s06T2RRVpWeDHI4xkFaDzJRfUB4","trackType":"qobuz"} May 15 13:34:04 mx-stream volumio[1010]: verbose: CURRENT POSITION 3 May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus play May 15 13:34:04 mx-stream volumio[1010]: info: Received an update from plugin. extracting info from payload May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:04 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:04 mx-stream volumio[1010]: info: ------------------------------ 107ms May 15 13:34:04 mx-stream volumio[1010]: info: ------------------------------ 103ms May 15 13:34:04 mx-stream volumio[1010]: info: Updating push state because input changed May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::volumiosetSourceActivempd May 15 13:34:04 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 13:34:04 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:04 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:04 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:05 mx-stream volumio[1010]: info: CoreCommandRouter::volumioNext May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:34:05 mx-stream volumio[1010]: info: [1747316045614] ControllerQobuz::next May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::next May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::stop May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:05 mx-stream volumio[1010]: verbose: UNSET VOLATILE May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:34:05 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:05 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:05 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:05 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::serviceStop May 15 13:34:05 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 3 May 15 13:34:05 mx-stream volumio[1010]: info: CoreCommandRouter::serviceStop May 15 13:34:05 mx-stream volumio[1010]: info: [1747316045619] ControllerQobuz::stop May 15 13:34:05 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:05 mx-stream volumio[1010]: info: ControllerMpd::stop May 15 13:34:05 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:34:05 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:07 mx-stream volumio[1010]: info: sendMpdCommand stop took 1387 milliseconds May 15 13:34:07 mx-stream volumio[1010]: info: CoreStateMachine::play index undefined May 15 13:34:07 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:07 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:07 mx-stream volumio[1010]: info: CoreStateMachine::startPlaybackTimer May 15 13:34:07 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:07 mx-stream volumio[1010]: info: [1747316047009] ControllerQobuz::clearAddPlayTrack May 15 13:34:07 mx-stream volumio[1010]: info: CoreStateMachine::updateTrackBlock May 15 13:34:07 mx-stream volumio[1010]: info: CorePlayQueue::getTrackBlock May 15 13:34:07 mx-stream volumio[1010]: info: May 15 13:34:07 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:07 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:07 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:07 mx-stream volumio[1010]: info: sendMpdCommand status took 12 milliseconds May 15 13:34:07 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:07 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:07 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 13:34:07 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:07 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:07 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:07 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:07 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:07 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:07 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:07 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:07 mx-stream volumio[1010]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 15 13:34:07 mx-stream volumio[1010]: info: ------------------------------ 29ms May 15 13:34:07 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:08 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPlay May 15 13:34:08 mx-stream volumio[1010]: verbose: UNSET VOLATILE May 15 13:34:08 mx-stream volumio[1010]: info: CoreStateMachine::play index undefined May 15 13:34:08 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 13:34:08 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:08 mx-stream volumio[1010]: info: CoreStateMachine::startPlaybackTimer May 15 13:34:08 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:08 mx-stream volumio[1010]: info: [1747316048231] ControllerQobuz::clearAddPlayTrack May 15 13:34:08 mx-stream volumio[1010]: info: getStreamUrl took 499 milliseconds May 15 13:34:08 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:34:08 mx-stream volumio[1010]: info: sendMpdCommand stop took 1 milliseconds May 15 13:34:08 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand clear May 15 13:34:08 mx-stream volumio[1010]: info: May 15 13:34:08 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:08 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:08 mx-stream volumio[1010]: info: sendMpdCommand clear took 2 milliseconds May 15 13:34:08 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs" May 15 13:34:08 mx-stream volumio[1010]: error: updateQueue error: null May 15 13:34:08 mx-stream volumio[1010]: info: ------------------------------ 3ms May 15 13:34:08 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs" May 15 13:34:08 mx-stream volumio[1010]: info: May 15 13:34:08 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:08 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:08 mx-stream volumio[1010]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs" took 5 milliseconds May 15 13:34:08 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:08 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand play May 15 13:34:08 mx-stream volumio[1010]: info: ------------------------------ 7ms May 15 13:34:08 mx-stream volumio[1010]: info: sendMpdCommand play took 6 milliseconds May 15 13:34:09 mx-stream volumio[1010]: info: May 15 13:34:09 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:09 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:09 mx-stream volumio[1010]: info: May 15 13:34:09 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:09 mx-stream volumio[1010]: info: sendMpdCommand status took 18 milliseconds May 15 13:34:09 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:09 mx-stream volumio[1010]: info: sendMpdCommand status took 8 milliseconds May 15 13:34:09 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:09 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:09 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:09 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":92,"duration":152,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"643 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","trackType":"qobuz"} May 15 13:34:09 mx-stream volumio[1010]: verbose: CURRENT POSITION 2 May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus stop May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:09 mx-stream volumio[1010]: info: ------------------------------ 45ms May 15 13:34:09 mx-stream volumio[1010]: info: Updating push state because input changed May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::volumiosetSourceActivempd May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 13:34:09 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:09 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 29 milliseconds May 15 13:34:09 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:09 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:09 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:09 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":152,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"623 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","trackType":"qobuz"} May 15 13:34:09 mx-stream volumio[1010]: verbose: CURRENT POSITION 2 May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus play May 15 13:34:09 mx-stream volumio[1010]: info: Received an update from plugin. extracting info from payload May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:09 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:09 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:09 mx-stream volumio[1010]: info: ------------------------------ 52ms May 15 13:34:09 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:09 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPause May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::pause May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::servicePause May 15 13:34:11 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::servicePause May 15 13:34:11 mx-stream volumio[1010]: info: [1747316051914] ControllerQobuz::pause May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:11 mx-stream volumio[1010]: info: ControllerMpd::pause May 15 13:34:11 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand pause May 15 13:34:11 mx-stream volumio[1010]: info: May 15 13:34:11 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:11 mx-stream volumio[1010]: info: sendMpdCommand pause took 28 milliseconds May 15 13:34:11 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:11 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:11 mx-stream volumio[1010]: info: sendMpdCommand status took 1 milliseconds May 15 13:34:11 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:11 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:11 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 13:34:11 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:11 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:11 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:11 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3204,"duration":152,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"611 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319648&hmac=PWYhS7HDpm0yu5vedrVEt_-Yhcs","trackType":"qobuz"} May 15 13:34:11 mx-stream volumio[1010]: verbose: CURRENT POSITION 2 May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService pause May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus pause May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:11 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:34:11 mx-stream volumio[1010]: info: ------------------------------ 15ms May 15 13:34:11 mx-stream volumio[1010]: info: Updating push state because input changed May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::volumiosetSourceActivempd May 15 13:34:11 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 13:34:11 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:12 mx-stream volumio[1010]: info: getStreamUrl took 5632 milliseconds May 15 13:34:12 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand stop May 15 13:34:13 mx-stream volumio[1010]: info: May 15 13:34:13 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand stop took 776 milliseconds May 15 13:34:13 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand clear May 15 13:34:13 mx-stream volumio[1010]: info: May 15 13:34:13 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:13 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand status took 2 milliseconds May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand clear took 2 milliseconds May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY" May 15 13:34:13 mx-stream volumio[1010]: error: updateQueue error: null May 15 13:34:13 mx-stream volumio[1010]: info: ------------------------------ 5ms May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:13 mx-stream volumio[1010]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 13:34:13 mx-stream volumio[1010]: info: ------------------------------ 10ms May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY" May 15 13:34:13 mx-stream volumio[1010]: info: May 15 13:34:13 mx-stream volumio[1010]: ---------------------------- MPD announces system playlist update May 15 13:34:13 mx-stream volumio[1010]: info: Ignoring MPD Status Update May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY" took 2 milliseconds May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand play May 15 13:34:13 mx-stream volumio[1010]: info: ------------------------------ 2ms May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand play took 2 milliseconds May 15 13:34:13 mx-stream volumio[1010]: info: May 15 13:34:13 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:13 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:13 mx-stream volumio[1010]: info: May 15 13:34:13 mx-stream volumio[1010]: ---------------------------- MPD announces state update: player May 15 13:34:13 mx-stream volumio[1010]: info: ControllerMpd::getState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand status May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand status took 6 milliseconds May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand status took 7 milliseconds May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseState May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 9 milliseconds May 15 13:34:13 mx-stream volumio[1010]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:13 mx-stream volumio[1010]: verbose: ControllerMpd::parseTrackInfo May 15 13:34:13 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:13 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:13 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":371,"duration":152,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"701 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY","trackType":"qobuz"} May 15 13:34:13 mx-stream volumio[1010]: verbose: CURRENT POSITION 2 May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus pause May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:13 mx-stream volumio[1010]: info: ControllerMpd::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::servicePushState May 15 13:34:13 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:13 mx-stream volumio[1010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":152,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"643 Kbps","isStreaming":false,"title":"file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=2949404&eid=63334114&fmt=6&profile=raw&app_id=539451548&cid=2539252&etsp=1747319652&hmac=m0NLDwi2T17gScOkdf1MO76n9SY","trackType":"qobuz"} May 15 13:34:13 mx-stream volumio[1010]: verbose: CURRENT POSITION 2 May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::syncState stateService play May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::syncState currentStatus play May 15 13:34:13 mx-stream volumio[1010]: info: Received an update from plugin. extracting info from payload May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:13 mx-stream volumio[1010]: info: CoreStateMachine::pushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPushState May 15 13:34:13 mx-stream volumio[1010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 13:34:13 mx-stream volumio[1010]: info: ------------------------------ 138ms May 15 13:34:13 mx-stream volumio[1010]: info: ------------------------------ 136ms May 15 13:34:13 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:13 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:13 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:13 mx-stream volumio[1010]: info: Updating RAAT Signal Path May 15 13:34:15 mx-stream volumio[1010]: info: CoreCommandRouter::volumioPause May 15 13:34:15 mx-stream volumio[1010]: info: CoreStateMachine::pause May 15 13:34:15 mx-stream volumio[1010]: info: CoreStateMachine::stPlaybackTimer May 15 13:34:15 mx-stream volumio[1010]: info: CoreStateMachine::servicePause May 15 13:34:15 mx-stream volumio[1010]: info: CorePlayQueue::getTrack 2 May 15 13:34:15 mx-stream volumio[1010]: info: CoreCommandRouter::servicePause May 15 13:34:15 mx-stream volumio[1010]: info: [1747316055337] ControllerQobuz::pause May 15 13:34:15 mx-stream volumio[1010]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 13:34:15 mx-stream volumio[1010]: info: ControllerMpd::pause May 15 13:34:15 mx-stream volumio[1010]: verbose: ControllerMpd::sendMpdCommand pause May 15 13:34:15 mx-stream systemd-journal[29556]: Runtime journal is using 12.0M (max allowed 30.0M, trying to leave 70.4M free of 456.9M available → current limit 30.0M). May 15 13:34:15 mx-stream kernel: Unable to handle kernel NULL pointer dereference at virtual address 00000222 May 15 13:34:15 mx-stream kernel: pgd = b927c000 May 15 13:34:15 mx-stream kernel: [00000222] *pgd=00000000 May 15 13:34:15 mx-stream kernel: Internal error: Oops: 5 [#1] SMP ARM May 15 13:34:15 mx-stream kernel: Modules linked in: bnep xt_REDIRECT nf_nat_redirect xt_tcpudp iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack ip_tables x_tables nfsd 8723bu(O) snd_usb_audio snd_hwdep snd_usbmidi_lib snd_seq_midi snd_seq_midi_event cfg80211 snd_rawmidi snd_pcm btusb(O) btrtl(O) btintel(O) btbcm(O) bluetooth snd_seq snd_seq_device snd_timer snd rfkill bcm2835_gpiomem fixed uio_pdrv_genirq uio i2c_dev ipv6 fuse squashfs overlay May 15 13:34:15 mx-stream kernel: CPU: 2 PID: 199 Comm: systemd-journal Tainted: G O 4.9.65-v7+ #1 May 15 13:34:15 mx-stream kernel: Hardware name: BCM2835 May 15 13:34:15 mx-stream kernel: task: ae80ac40 task.stack: b91fa000 May 15 13:34:15 mx-stream kernel: PC is at skb_release_data+0x64/0x128 May 15 13:34:15 mx-stream kernel: LR is at skb_release_all+0x30/0x34 May 15 13:34:15 mx-stream kernel: pc : [<805fff80>] lr : [<80600074>] psr: 60000013 sp : b91fbd78 ip : b91fbd98 fp : b91fbd94 May 15 13:34:15 mx-stream kernel: r10: b666fc00 r9 : 00000000 r8 : 00000000 May 15 13:34:15 mx-stream kernel: r7 : 00000222 r6 : 91b0e0c0 r5 : 91b0e0c0 r4 : 91b0e0c0 May 15 13:34:15 mx-stream kernel: r3 : 00000000 r2 : 00000001 r1 : 00000000 r0 : 91b0e0c0 May 15 13:34:15 mx-stream kernel: Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user May 15 13:34:15 mx-stream kernel: Control: 10c5383d Table: 3927c06a DAC: 00000055 May 15 13:34:15 mx-stream kernel: Process systemd-journal (pid: 199, stack limit = 0xb91fa210) May 15 13:34:15 mx-stream kernel: Stack: (0xb91fbd78 to 0xb91fc000) May 15 13:34:15 mx-stream kernel: bd60: 91b0e0c0 91b0e0c0 May 15 13:34:15 mx-stream kernel: bd80: b91fbe5c 000007b9 b91fbdac b91fbd98 80600074 805fff28 00000001 91b0e0c0 May 15 13:34:15 mx-stream kernel: bda0: b91fbdc4 b91fbdb0 806001f8 80600050 91b0e0c0 00000047 b91fbe54 b91fbdc8 May 15 13:34:15 mx-stream kernel: bdc0: 806c2264 806001cc b91fbe3c b91fbdd8 b666fd44 00000001 00000000 00000001 May 15 13:34:15 mx-stream kernel: bde0: b666fe0c 00000000 b666fe4c b5253500 00000047 00000001 00000047 b666fc84 May 15 13:34:15 mx-stream kernel: be00: ba9a0140 00000000 000003f2 000003e8 000003e8 b91fa000 00000000 00000000 May 15 13:34:15 mx-stream kernel: be20: 00000000 00000000 00000000 00000000 b91fbf00 b91fbee8 b91fbf78 00000800 May 15 13:34:15 mx-stream kernel: be40: 01138d89 00000000 b91fbe84 b91fbe58 806c2410 806c1b10 806bdb84 806be394 May 15 13:34:15 mx-stream kernel: be60: b5253500 b91fbe88 00000000 00000800 00000040 00000000 b91fbed4 b91fbe88 May 15 13:34:15 mx-stream kernel: be80: 805f71e0 806c23d4 00000000 00000000 00000000 00000047 000007b9 b91fbee0 May 15 13:34:15 mx-stream kernel: bea0: 00000001 805c88c0 00000000 00000000 00000040 b91fbf00 ae9fd82c 00000000 May 15 13:34:15 mx-stream kernel: bec0: 00000000 b6794f00 b91fbf44 b91fbed8 80268b64 805f7150 00000800 0000001e May 15 13:34:15 mx-stream kernel: bee0: 01138d89 00000800 00000000 00000000 00000800 b91fbee0 00000001 805c88c0 May 15 13:34:15 mx-stream kernel: bf00: b6794f00 00000000 00000000 00000000 00000000 00000000 00000000 00000000 May 15 13:34:15 mx-stream kernel: bf20: 8017ea84 00000800 b6794f00 01138d89 b91fbf78 00000800 b91fbf74 b91fbf48 May 15 13:34:15 mx-stream kernel: bf40: 8026996c 80268aa0 00004953 80289034 b91fbf74 00000000 00000000 b6794f00 May 15 13:34:15 mx-stream kernel: bf60: b6794f00 00000800 b91fbfa4 b91fbf78 8026ab28 802698e0 00000000 00000000 May 15 13:34:15 mx-stream kernel: bf80: 01138d60 76f00f10 7ec1b728 00000003 80107fa4 b91fa000 00000000 b91fbfa8 May 15 13:34:15 mx-stream kernel: bfa0: 80107e20 8026aae8 01138d60 76f00f10 0000001a 01138d89 00000800 00000011 May 15 13:34:15 mx-stream kernel: bfc0: 01138d60 76f00f10 7ec1b728 00000003 76f00f10 011290a0 01129088 7ec1ba1c May 15 13:34:15 mx-stream kernel: bfe0: 00000000 7ec1b704 0050be78 76eb7c8c 60000010 0000001a 3b7fa861 3b7fac61 May 15 13:34:15 mx-stream kernel: [<805fff80>] (skb_release_data) from [<80600074>] (skb_release_all+0x30/0x34) May 15 13:34:15 mx-stream kernel: [<80600074>] (skb_release_all) from [<806001f8>] (consume_skb+0x38/0xe4) May 15 13:34:15 mx-stream kernel: [<806001f8>] (consume_skb) from [<806c2264>] (unix_stream_read_generic+0x760/0x834) May 15 13:34:15 mx-stream kernel: [<806c2264>] (unix_stream_read_generic) from [<806c2410>] (unix_stream_recvmsg+0x48/0x54) May 15 13:34:15 mx-stream kernel: [<806c2410>] (unix_stream_recvmsg) from [<805f71e0>] (sock_read_iter+0x9c/0xd0) May 15 13:34:15 mx-stream kernel: [<805f71e0>] (sock_read_iter) from [<80268b64>] (__vfs_read+0xd0/0x120) May 15 13:34:15 mx-stream kernel: [<80268b64>] (__vfs_read) from [<8026996c>] (vfs_read+0x98/0x16c) May 15 13:34:15 mx-stream kernel: [<8026996c>] (vfs_read) from [<8026ab28>] (SyS_read+0x4c/0xa0) May 15 13:34:15 mx-stream kernel: [<8026ab28>] (SyS_read) from [<80107e20>] (ret_fast_syscall+0x0/0x1c) May 15 13:34:15 mx-stream kernel: Code: 1afffffa f57ff05b e3510000 189da8f0 (e5d73000) May 15 13:34:15 mx-stream kernel: ---[ end trace 789e10c7d932f344 ]--- May 15 13:34:15 mx-stream systemd[1]: systemd-journald.service has no holdoff time, scheduling restart. May 15 13:34:15 mx-stream systemd[1]: Stopping Journal Service... May 15 13:34:15 mx-stream systemd[1]: Starting Journal Service... May 15 13:34:15 mx-stream systemd[1]: Started Journal Service. May 15 13:34:15 mx-stream systemd-journal[29556]: Journal started May 15 13:34:15 mx-stream systemd[1]: systemd-journald.service: main process exited, code=killed, status=11/SEGV May 15 13:34:15 mx-stream systemd[1]: Unit systemd-journald.service entered failed state. May 15 13:34:15 mx-stream systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage... May 15 13:34:15 mx-stream systemd[1]: Started Trigger Flushing of Journal to Persistent Storage. May 15 13:34:16 mx-stream sudo[29572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-15 13:33 May 15 13:34:16 mx-stream sudo[29572]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="6d9442f761618503268d0366db805a252514dec1" VOLUMIO_BE_VERSION="3e944f35d34b575025d16b976b4cb4d9aed53b66" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="mf" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Jul 13 16:55:24 CEST 2022" VOLUMIO_VERSION="1.079" VOLUMIO_HARDWARE="pi" VOLUMIO_VENDOR="Musical Fidelity" VOLUMIO_MODEL="MX-Stream" VOLUMIO_VENDOR_MODEL="Musical Fidelity MX-Stream" VOLUMIO_HASH="feef4003d1cbcf074f611a1d9cb9a86e"