-- Logs begin at Sat 2024-03-30 12:00:52 CET, end at Sun 2024-03-31 19:27:48 CEST. --
Mar 31 19:26:29 rivo volumio[5432]: info: Preload queue cleared
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::ClearQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::stop
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::stPlaybackTimer
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::updateTrackBlock
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrackBlock
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrack 23
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::serviceStop
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrack 23
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::serviceStop
Mar 31 19:26:29 rivo volumio[5432]: info: [1711905989339] ControllerQobuz::stop
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 31 19:26:29 rivo volumio[5432]: info: ControllerMpd::stop
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand stop
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::clearPlayQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::saveQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::addQueueItems
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::addQueueItems
Mar 31 19:26:29 rivo volumio[5432]: info: Preload queue cleared
Mar 31 19:26:29 rivo volumio[5432]: info: Adding Item to queue: qobuz://song/1013077
Mar 31 19:26:29 rivo volumio[5432]: info: Exploding uri qobuz://song/1013077 in service qobuz
Mar 31 19:26:29 rivo volumio[5432]: info: Adding Item to queue: qobuz://song/1013071
Mar 31 19:26:29 rivo volumio[5432]: info: Exploding uri qobuz://song/1013071 in service qobuz
Mar 31 19:26:29 rivo volumio[5432]: info: Adding Item to queue: qobuz://song/1013078
Mar 31 19:26:29 rivo volumio[5432]: info: Exploding uri qobuz://song/1013078 in service qobuz
Mar 31 19:26:29 rivo volumio[5432]: info: Adding Item to queue: qobuz://song/1013079
Mar 31 19:26:29 rivo volumio[5432]: info: Exploding uri qobuz://song/1013079 in service qobuz
Mar 31 19:26:29 rivo volumio[5432]: info: Adding Item to queue: qobuz://song/1013080
Mar 31 19:26:29 rivo volumio[5432]: info: Exploding uri qobuz://song/1013080 in service qobuz
Mar 31 19:26:29 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:29 rivo volumio[5432]: info:
Mar 31 19:26:29 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:29 rivo volumio[5432]: info: sendMpdCommand stop took 53 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:29 rivo volumio[5432]: info: sendMpdCommand status took 15 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:29 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:29 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrack 23
Mar 31 19:26:29 rivo volumio[5432]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1235206","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1235206","trackType":"qobuz"}
Mar 31 19:26:29 rivo volumio[5432]: verbose: CURRENT POSITION 23
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::syncState stateService stop
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus stop
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:29 rivo volumio[5432]: info: No code
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:29 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:29 rivo volumio[5432]: info: ------------------------------ 49ms
Mar 31 19:26:29 rivo volumio[5432]: info: MCU Signalled Playback Inactive
Mar 31 19:26:29 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:29 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:29 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:29 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:29 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:29 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:29 rivo volumio[5432]: info: MCU Signalled Playback Active
Mar 31 19:26:29 rivo volumio[5432]: info: explodeUri took 439 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: explodeUri took 481 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: explodeUri took 486 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: explodeUri took 494 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: explodeUri took 500 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPushQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::saveQueue
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::updateTrackBlock
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrackBlock
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::volumioPlay
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::play index 0
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::stop
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::play index undefined
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:29 rivo volumio[5432]: info: CoreStateMachine::startPlaybackTimer
Mar 31 19:26:29 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:29 rivo volumio[5432]: info: [1711905989858] ControllerQobuz::clearAddPlayTrack
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand stop
Mar 31 19:26:29 rivo volumio[5432]: info: sendMpdCommand stop took 3 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand clear
Mar 31 19:26:29 rivo volumio[5432]: info:
Mar 31 19:26:29 rivo volumio[5432]: ---------------------------- MPD announces system playlist update
Mar 31 19:26:29 rivo volumio[5432]: info: Ignoring MPD Status Update
Mar 31 19:26:29 rivo volumio[5432]: info: sendMpdCommand clear took 4 milliseconds
Mar 31 19:26:29 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/1013077"
Mar 31 19:26:29 rivo volumio[5432]: error: updateQueue error: null
Mar 31 19:26:29 rivo volumio[5432]: info: ------------------------------ 4ms
Mar 31 19:26:29 rivo volumio[5432]: STREAMING PROXY: Handling url /?data=qobuz://song/1013077
Mar 31 19:26:29 rivo volumio[5432]: info: Executing endpoint getStreamUrlqobuz
Mar 31 19:26:29 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 31 19:26:30 rivo volumio[5432]: info: getStreamUrl took 302 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=1013077&fmt=6&profile=raw&app_id=539451548&cid=1966015&etsp=1711909590&hmac=iJZOjNzTSf1BwgC8Bd0lS0mtx_o
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Response: 200, length: 13245063
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Client dropped request, destroying
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/1013077"
Mar 31 19:26:30 rivo volumio[5432]: info:
Mar 31 19:26:30 rivo volumio[5432]: ---------------------------- MPD announces system playlist update
Mar 31 19:26:30 rivo volumio[5432]: info: Ignoring MPD Status Update
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/1013077" took 2 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand play
Mar 31 19:26:30 rivo volumio[5432]: info: ------------------------------ 3ms
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand play took 2 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Handling url /?data=qobuz://song/1013077
Mar 31 19:26:30 rivo volumio[5432]: info: Executing endpoint getStreamUrlqobuz
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 31 19:26:30 rivo volumio[5432]: info: getStreamUrl took 309 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=1013077&fmt=6&profile=raw&app_id=539451548&cid=1966015&etsp=1711909590&hmac=iJZOjNzTSf1BwgC8Bd0lS0mtx_o
Mar 31 19:26:30 rivo volumio[5432]: STREAMING PROXY: Response: 200, length: 13245063
Mar 31 19:26:30 rivo volumio[5432]: info:
Mar 31 19:26:30 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:30 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand status took 26 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:30 rivo volumio[5432]: info:
Mar 31 19:26:30 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:30 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 4 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:30 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:30 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:30 rivo volumio[5432]: 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":"1013077","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1013077","trackType":"qobuz"}
Mar 31 19:26:30 rivo volumio[5432]: verbose: CURRENT POSITION 0
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::syncState stateService play
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus stop
Mar 31 19:26:30 rivo volumio[5432]: info: ------------------------------ 42ms
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand status took 9 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:30 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 31 19:26:30 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:30 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:30 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:30 rivo volumio[5432]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":179,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"605 Kbps","isStreaming":false,"title":"1013077","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1013077","trackType":"qobuz"}
Mar 31 19:26:30 rivo volumio[5432]: verbose: CURRENT POSITION 0
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::syncState stateService play
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus play
Mar 31 19:26:30 rivo volumio[5432]: info: Received an update from plugin. extracting info from payload
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:30 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:30 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:30 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:30 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:30 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:30 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:30 rivo volumio[5432]: info: ------------------------------ 59ms
Mar 31 19:26:30 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:30 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:30 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:30 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:32 rivo volumio[5432]: STREAMING PROXY: Client dropped request, destroying
Mar 31 19:26:33 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:33 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:33 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:33 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:33 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:33 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:44 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:44 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , goto
Mar 31 19:26:45 rivo volumio[5432]: info: explodeUri took 272 milliseconds
Mar 31 19:26:45 rivo volumio[5432]: info: handleBrowseUri took 682 milliseconds
Mar 31 19:26:45 rivo volumio[5432]: info: Executing endpoint getSimilarAlbums
Mar 31 19:26:45 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Mar 31 19:26:45 rivo volumio[5432]: info: Executing endpoint getSimilarAlbums
Mar 31 19:26:45 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums
Mar 31 19:26:46 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:46 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:46 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:46 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:46 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:46 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:46 rivo volumio[5432]: info: Executing endpoint metavolumio
Mar 31 19:26:46 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 31 19:26:52 rivo volumio[5432]: info: Preload queue cleared
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::ClearQueue
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::stop
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::stPlaybackTimer
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::updateTrackBlock
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::getTrackBlock
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::serviceStop
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::serviceStop
Mar 31 19:26:52 rivo volumio[5432]: info: [1711906012787] ControllerQobuz::stop
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 31 19:26:52 rivo volumio[5432]: info: ControllerMpd::stop
Mar 31 19:26:52 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand stop
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::clearPlayQueue
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::saveQueue
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioPushQueue
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::addQueueItems
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::addQueueItems
Mar 31 19:26:52 rivo volumio[5432]: info: Preload queue cleared
Mar 31 19:26:52 rivo volumio[5432]: info: Adding Item to queue: qobuz://album/0724354536656
Mar 31 19:26:52 rivo volumio[5432]: info: Exploding uri qobuz://album/0724354536656 in service qobuz
Mar 31 19:26:52 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:52 rivo volumio[5432]: info:
Mar 31 19:26:52 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:52 rivo volumio[5432]: info: sendMpdCommand stop took 53 milliseconds
Mar 31 19:26:52 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:52 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:52 rivo volumio[5432]: info: sendMpdCommand status took 3 milliseconds
Mar 31 19:26:52 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:52 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:52 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 31 19:26:52 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:52 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:52 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:52 rivo volumio[5432]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1013077","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1013077","trackType":"qobuz"}
Mar 31 19:26:52 rivo volumio[5432]: verbose: CURRENT POSITION 0
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::syncState stateService stop
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus stop
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:52 rivo volumio[5432]: info: No code
Mar 31 19:26:52 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:52 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:52 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:52 rivo volumio[5432]: info: ------------------------------ 52ms
Mar 31 19:26:52 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:52 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:52 rivo volumio[5432]: info: MCU Signalled Playback Inactive
Mar 31 19:26:52 rivo volumio[5432]: info: MCU Signalled Playback Active
Mar 31 19:26:52 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:52 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:52 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:52 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:53 rivo volumio[5432]: error: Failed request for metavolumio API
Mar 31 19:26:53 rivo volumio[5432]: error: Failed request for metavolumio API
Mar 31 19:26:53 rivo volumio[5432]: info: explodeUri took 477 milliseconds
Mar 31 19:26:53 rivo volumio[5432]: info: CoreCommandRouter::volumioPushQueue
Mar 31 19:26:53 rivo volumio[5432]: info: CorePlayQueue::saveQueue
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::updateTrackBlock
Mar 31 19:26:53 rivo volumio[5432]: info: CorePlayQueue::getTrackBlock
Mar 31 19:26:53 rivo volumio[5432]: info: CoreCommandRouter::volumioPlay
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::play index 0
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::stop
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::play index undefined
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 31 19:26:53 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:53 rivo volumio[5432]: info: CoreStateMachine::startPlaybackTimer
Mar 31 19:26:53 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:53 rivo volumio[5432]: info: [1711906013298] ControllerQobuz::clearAddPlayTrack
Mar 31 19:26:53 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand stop
Mar 31 19:26:53 rivo volumio[5432]: info: sendMpdCommand stop took 6 milliseconds
Mar 31 19:26:53 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand clear
Mar 31 19:26:53 rivo volumio[5432]: info:
Mar 31 19:26:53 rivo volumio[5432]: ---------------------------- MPD announces system playlist update
Mar 31 19:26:53 rivo volumio[5432]: info: Ignoring MPD Status Update
Mar 31 19:26:53 rivo volumio[5432]: info: sendMpdCommand clear took 14 milliseconds
Mar 31 19:26:53 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/1013071"
Mar 31 19:26:53 rivo volumio[5432]: STREAMING PROXY: Handling url /?data=qobuz://song/1013071
Mar 31 19:26:53 rivo volumio[5432]: error: updateQueue error: null
Mar 31 19:26:53 rivo volumio[5432]: info: ------------------------------ 4ms
Mar 31 19:26:53 rivo volumio[5432]: info: Executing endpoint getStreamUrlqobuz
Mar 31 19:26:53 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 31 19:26:53 rivo volumio[5432]: info: getStreamUrl took 368 milliseconds
Mar 31 19:26:53 rivo volumio[5432]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=1013071&fmt=6&profile=raw&app_id=539451548&cid=1966015&etsp=1711909613&hmac=8W0TVGMQpYBvo8zacyFNr3rJYGE
Mar 31 19:26:53 rivo volumio[5432]: STREAMING PROXY: Response: 200, length: 13521734
Mar 31 19:26:54 rivo volumio[5432]: STREAMING PROXY: Client dropped request, destroying
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/1013071"
Mar 31 19:26:54 rivo volumio[5432]: info:
Mar 31 19:26:54 rivo volumio[5432]: ---------------------------- MPD announces system playlist update
Mar 31 19:26:54 rivo volumio[5432]: info: Ignoring MPD Status Update
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/1013071" took 2 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::setConsumeUpdateService mpd
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand play
Mar 31 19:26:54 rivo volumio[5432]: info: ------------------------------ 4ms
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand play took 2 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: STREAMING PROXY: Handling url /?data=qobuz://song/1013071
Mar 31 19:26:54 rivo volumio[5432]: info: Executing endpoint getStreamUrlqobuz
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI
Mar 31 19:26:54 rivo volumio[5432]: info: getStreamUrl took 296 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=1013071&fmt=6&profile=raw&app_id=539451548&cid=1966015&etsp=1711909614&hmac=VjqejpuITk3lqHV7cXx49agdBaM
Mar 31 19:26:54 rivo volumio[5432]: STREAMING PROXY: Response: 200, length: 13521734
Mar 31 19:26:54 rivo volumio[5432]: info:
Mar 31 19:26:54 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:54 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:54 rivo volumio[5432]: info:
Mar 31 19:26:54 rivo volumio[5432]: ---------------------------- MPD announces state update: player
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand status took 21 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: info: ControllerMpd::getState
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand status
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand status took 5 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 4 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::parseState
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:54 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:54 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:54 rivo volumio[5432]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":159,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1013071","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1013071","trackType":"qobuz"}
Mar 31 19:26:54 rivo volumio[5432]: verbose: CURRENT POSITION 0
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::syncState stateService play
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus stop
Mar 31 19:26:54 rivo volumio[5432]: info: ------------------------------ 36ms
Mar 31 19:26:54 rivo volumio[5432]: info: sendMpdCommand playlistinfo took 6 milliseconds
Mar 31 19:26:54 rivo volumio[5432]: verbose: ControllerMpd::parseTrackInfo
Mar 31 19:26:54 rivo volumio[5432]: info: ControllerMpd::pushState
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::servicePushState
Mar 31 19:26:54 rivo volumio[5432]: info: CorePlayQueue::getTrack 0
Mar 31 19:26:54 rivo volumio[5432]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":159,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"758 Kbps","isStreaming":false,"title":"1013071","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/1013071","trackType":"qobuz"}
Mar 31 19:26:54 rivo volumio[5432]: verbose: CURRENT POSITION 0
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::syncState stateService play
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::syncState currentStatus play
Mar 31 19:26:54 rivo volumio[5432]: info: Received an update from plugin. extracting info from payload
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:54 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:54 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:54 rivo volumio[5432]: info: CoreStateMachine::pushState
Mar 31 19:26:54 rivo volumio[5432]: info: CoreCommandRouter::volumioPushState
Mar 31 19:26:54 rivo volumio[5432]: info: MRS: Pushing multiroomSync output update for this device
Mar 31 19:26:54 rivo volumio[5432]: info: MRS: Pushing multiroomSync output
Mar 31 19:26:54 rivo volumio[5432]: info: ------------------------------ 53ms
Mar 31 19:26:54 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:54 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:54 rivo volumio[5432]: info: Signalling Playback active due to playback status change
Mar 31 19:26:54 rivo volumio[5432]: info: Updating RAAT Signal Path
Mar 31 19:26:55 rivo volumio[5432]: STREAMING PROXY: Client dropped request, destroying
Mar 31 19:27:47 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: qobuz , explodeUri
Mar 31 19:27:48 rivo volumio[5432]: info: explodeUri took 300 milliseconds
Mar 31 19:27:48 rivo volumio[5432]: info: Saving Cloud item A. Scarlatti Stabat Mater
Mar 31 19:27:48 rivo volumio[5432]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem
Mar 31 19:27:48 rivo volumio[5432]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 31 19:27:48 rivo volumio[5432]: Error: Reference.child failed: First argument was an invalid path = "/user_data/HChUTMmKbaa2hksy3Jz8ffWfeeU2/myPlaylists/A. Scarlatti Stabat Mater". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]"
Mar 31 19:27:48 rivo volumio[5432]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15)
Mar 31 19:27:48 rivo volumio[5432]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5)
Mar 31 19:27:48 rivo volumio[5432]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17)
Mar 31 19:27:48 rivo volumio[5432]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48)
Mar 31 19:27:48 rivo volumio[5432]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817)
Mar 31 19:27:48 rivo volumio[5432]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840)
Mar 31 19:27:48 rivo volumio[5432]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337)
Mar 31 19:27:48 rivo volumio[5432]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32)
Mar 31 19:27:48 rivo volumio[5432]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31)
Mar 31 19:27:48 rivo volumio[5432]: at /volumio/app/playlistManager.js:588:20
Mar 31 19:27:48 rivo volumio[5432]: at /volumio/node_modules/jsonfile/index.js:46:5
Mar 31 19:27:48 rivo volumio[5432]: at /volumio/node_modules/graceful-fs/graceful-fs.js:123:16
Mar 31 19:27:48 rivo volumio[5432]: at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:71:3)
Mar 31 19:27:48 rivo volumio[5432]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 31 19:27:48 rivo sudo[6752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-31 19:26
Mar 31 19:27:48 rivo sudo[6752]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="rivo"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:41:55 AM CET"
VOLUMIO_VERSION="3.629"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Rivo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Rivo"
VOLUMIO_HASH="b0437c7088d6645a661a49f6d9fa596a"