-- Logs begin at Wed 2024-12-25 18:55:26 AWST, end at Mon 2025-03-17 10:24:32 AWST. -- Mar 17 10:23:02 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: my_music , getSuperSearchEnabledSourcesList Mar 17 10:23:02 rivo volumio[3428]: info: CoreCommandRouter::volumioGetBrowseSources Mar 17 10:23:02 rivo volumio[3428]: info: CoreCommandRouter::volumioGetBrowseSources Mar 17 10:23:02 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 17 10:23:02 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 17 10:23:03 rivo volumio[3428]: info: searchTIDALUri took 642 milliseconds Mar 17 10:23:03 rivo volumio[3428]: info: search took 644 milliseconds Mar 17 10:23:03 rivo volumio[3428]: info: All search sources collected, pushing search results Mar 17 10:23:03 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 17 10:23:04 rivo volumio[3428]: info: browseTIDALUri took 773 milliseconds Mar 17 10:23:04 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440075 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440076 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440077 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440078 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440079 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440082 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440083 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440084 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440085 Mar 17 10:23:04 rivo volumio[3428]: info: Preloading song: tidal://song/94440086 Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440075 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440076 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440077 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440078 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440079 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440082 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Executing endpoint getSimilarAlbums Mar 17 10:23:04 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 17 10:23:04 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:04 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:04 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:04 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440083 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440084 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440085 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: Exploding uri tidal://song/94440086 in service tidal Mar 17 10:23:04 rivo volumio[3428]: info: explodeTIDALUri took 487 milliseconds Mar 17 10:23:04 rivo volumio[3428]: info: explodeTIDALUri took 514 milliseconds Mar 17 10:23:04 rivo volumio[3428]: info: explodeTIDALUri took 504 milliseconds Mar 17 10:23:09 rivo volumio[3428]: info: explodeTIDALUri took 5485 milliseconds Mar 17 10:23:09 rivo volumio[3428]: info: explodeTIDALUri took 5437 milliseconds Mar 17 10:23:09 rivo volumio[3428]: info: explodeTIDALUri took 5497 milliseconds Mar 17 10:23:09 rivo volumio[3428]: info: explodeTIDALUri took 5360 milliseconds Mar 17 10:23:09 rivo volumio[3428]: info: explodeTIDALUri took 5377 milliseconds Mar 17 10:23:10 rivo volumio[3428]: info: explodeTIDALUri took 5347 milliseconds Mar 17 10:23:10 rivo volumio[3428]: info: explodeTIDALUri took 5322 milliseconds Mar 17 10:23:23 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 10:23:23 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 10:23:23 rivo volumio[3428]: info: Discovery: Getting this device information Mar 17 10:23:23 rivo volumio[3428]: info: CoreCommandRouter::volumioGetState Mar 17 10:23:23 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:23 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 10:23:37 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:37 rivo volumio[3428]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 17 10:23:37 rivo volumio[3428]: info: CoreStateMachine::ClearQueue Mar 17 10:23:37 rivo volumio[3428]: info: CoreStateMachine::stop Mar 17 10:23:37 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:37 rivo volumio[3428]: info: CorePlayQueue::clearPlayQueue Mar 17 10:23:37 rivo volumio[3428]: info: CorePlayQueue::saveQueue Mar 17 10:23:37 rivo volumio[3428]: info: CoreCommandRouter::volumioPushQueue Mar 17 10:23:37 rivo volumio[3428]: info: CoreStateMachine::addQueueItems Mar 17 10:23:37 rivo volumio[3428]: info: CorePlayQueue::addQueueItems Mar 17 10:23:37 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:37 rivo volumio[3428]: info: Adding Item to queue: tidal://album/94440074 Mar 17 10:23:37 rivo volumio[3428]: info: Exploding uri tidal://album/94440074 in service tidal Mar 17 10:23:38 rivo volumio[3428]: info: explodeTIDALUri took 933 milliseconds Mar 17 10:23:38 rivo volumio[3428]: info: CoreCommandRouter::volumioPushQueue Mar 17 10:23:38 rivo volumio[3428]: info: CorePlayQueue::saveQueue Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::updateTrackBlock Mar 17 10:23:38 rivo volumio[3428]: info: CorePlayQueue::getTrackBlock Mar 17 10:23:38 rivo volumio[3428]: info: CoreCommandRouter::volumioPlay Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::play index 0 Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::stop Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::play index undefined Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:38 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::startPlaybackTimer Mar 17 10:23:38 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:38 rivo volumio[3428]: info: [1742178218718] ControllerTidal::clearAddPlayTrack Mar 17 10:23:38 rivo volumio[3428]: info: Getting stream with soundQuality HI_RES Mar 17 10:23:38 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand stop Mar 17 10:23:38 rivo volumio[3428]: info: sendMpdCommand stop took 9 milliseconds Mar 17 10:23:38 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand clear Mar 17 10:23:38 rivo volumio[3428]: info: sendMpdCommand clear took 1 milliseconds Mar 17 10:23:38 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES" Mar 17 10:23:38 rivo volumio[3428]: info: Mar 17 10:23:38 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:38 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:38 rivo volumio[3428]: info: Mar 17 10:23:38 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:38 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:38 rivo volumio[3428]: info: Mar 17 10:23:38 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:38 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:38 rivo volumio[3428]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES" took 9 milliseconds Mar 17 10:23:38 rivo volumio[3428]: info: ------------------------------ 7ms Mar 17 10:23:38 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 17 10:23:38 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand play Mar 17 10:23:38 rivo volumio[3428]: info: Mar 17 10:23:38 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:38 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:38 rivo volumio[3428]: error: Upnp client error: Error: This socket has been ended by the other party Mar 17 10:23:38 rivo volumio[3428]: info: ------------------------------ 13ms Mar 17 10:23:38 rivo volumio[3428]: info: sendMpdCommand play took 26 milliseconds Mar 17 10:23:38 rivo volumio[3428]: info: ------------------------------ 26ms Mar 17 10:23:38 rivo volumio[3428]: STREAMING PROXY: Handling url /?data=tidal://song/94440075&soundQuality=HI_RES Mar 17 10:23:38 rivo volumio[3428]: info: Executing endpoint getStreamUrltidal Mar 17 10:23:38 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Mar 17 10:23:39 rivo volumio[3428]: info: getStreamUrl took 570 milliseconds Mar 17 10:23:39 rivo volumio[3428]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEicyZTkzZjFhMjc4ZDJhM2Y3YTU2ZWNiODFjMmM0ZjMwMV82MS5tcDQ/0.flac?Expires=1742181819&Signature=p7N0~mR8RRLdicKR0CN3iIKfzvnAqKYLB17~tPjuwMyisvVglPPXSXkN5zX-lV9Z~OzPpwPP7rFMCc92xbIWRUCTYEuM8s1M2A41-5Thdexf~3-CGaJiJaFH7REESwZAWiQs791-Fa8wSSyd9TJQoSqzRGntXxrWSJ-Mv4Tnm8UTuk9X9fr~eREyerF~5t944ixDZl8n2x-tOxzaP9jet6tx8sor4lSIMKfZ6e88naNVnlvycUu5oZboW-hrB3w7yxT1kGq7X5gXKinSFJbZydVwROuMD8bU8Ng7oaCKcUJso~rfIkguF4xaIeplKGkP~4cI0x9O6kjwqmu8vE2MXA__&Key-Pair-Id=K14LZCZ9QUI4JL Mar 17 10:23:40 rivo volumio[3428]: STREAMING PROXY: Response: 200, length: 28771248 Mar 17 10:23:40 rivo volumio[3428]: info: Mar 17 10:23:40 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:40 rivo volumio[3428]: info: Mar 17 10:23:40 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:40 rivo kernel: aml_spdif_open Mar 17 10:23:40 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Mar 17 10:23:40 rivo kernel: set normal 512 fs /4 fs Mar 17 10:23:40 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 17 10:23:40 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 17 10:23:40 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Mar 17 10:23:40 rivo kernel: set normal 512 fs /4 fs Mar 17 10:23:40 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 17 10:23:40 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 17 10:23:40 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 17 10:23:40 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Mar 17 10:23:40 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 17 10:23:40 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand status took 16 milliseconds Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:40 rivo volumio[3428]: info: Mar 17 10:23:40 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand status took 25 milliseconds Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 9 milliseconds Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:40 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:40 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"94440075&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:40 rivo volumio[3428]: verbose: CURRENT POSITION 0 Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus stop Mar 17 10:23:40 rivo volumio[3428]: info: ------------------------------ 47ms Mar 17 10:23:40 rivo volumio[3428]: info: Mar 17 10:23:40 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand status took 23 milliseconds Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 18 milliseconds Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand status took 4 milliseconds Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:40 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:40 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"94440075&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:40 rivo volumio[3428]: verbose: CURRENT POSITION 0 Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:40 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: ------------------------------ 103ms Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 53 milliseconds Mar 17 10:23:40 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 52 milliseconds Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:40 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:40 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:40 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"94440075&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:40 rivo volumio[3428]: verbose: CURRENT POSITION 0 Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:40 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:40 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:40 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"94440075&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/94440075&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:40 rivo volumio[3428]: verbose: CURRENT POSITION 0 Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:40 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:40 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:40 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:40 rivo volumio[3428]: info: ------------------------------ 176ms Mar 17 10:23:40 rivo volumio[3428]: info: ------------------------------ 153ms Mar 17 10:23:40 rivo volumio[3428]: info: Signalling Playback active due to playback status change Mar 17 10:23:40 rivo volumio[3428]: info: MCU Signalled Playback Active Mar 17 10:23:40 rivo volumio[3428]: info: MCU Signalled Sleep Mode Disabled Mar 17 10:23:40 rivo sudo[10308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Mar 17 10:23:40 rivo sudo[10308]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 10:23:40 rivo kernel: fb: osd[0] enable: 1 (Xorg) Mar 17 10:23:40 rivo kernel: fb: osd[0] enable: 1 (Xorg) Mar 17 10:23:40 rivo sudo[10308]: pam_unix(sudo:session): session closed for user root Mar 17 10:23:40 rivo sudo[10311]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Mar 17 10:23:40 rivo sudo[10311]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 17 10:23:40 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Mar 17 10:23:40 rivo sudo[10311]: pam_unix(sudo:session): session closed for user root Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 10:23:42 rivo volumio[3428]: info: Discovery: Getting this device information Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::volumioGetState Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 10:23:42 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:42 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:42 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:42 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:43 rivo volumio[3428]: STREAMING PROXY: Client dropped request, destroying Mar 17 10:23:52 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::ClearQueue Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::stop Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::stPlaybackTimer Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::updateTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:52 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:52 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::serviceStop Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 0 Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::serviceStop Mar 17 10:23:52 rivo volumio[3428]: info: [1742178232182] ControllerTidal::stop Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 17 10:23:52 rivo volumio[3428]: info: ControllerMpd::stop Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand stop Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::clearPlayQueue Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::saveQueue Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPushQueue Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::addQueueItems Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::addQueueItems Mar 17 10:23:52 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980357 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980357 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980358 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980358 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980359 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980359 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980360 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980360 Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPushQueue Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::saveQueue Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::updateTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPlay Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::play index 3 Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::addQueueItems Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::addQueueItems Mar 17 10:23:52 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980361 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980361 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980362 Mar 17 10:23:52 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Mar 17 10:23:52 rivo kernel: spdif_a keep clk continuous Mar 17 10:23:52 rivo kernel: aml_spdif_close Mar 17 10:23:52 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980362 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980363 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980363 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980364 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980364 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980365 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980365 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980366 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980366 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980367 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980367 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980368 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980368 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980369 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980369 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980370 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980370 Mar 17 10:23:52 rivo volumio[3428]: info: Adding Item to queue: tidal://song/35980371 Mar 17 10:23:52 rivo volumio[3428]: info: Using cached record of: tidal://song/35980371 Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::stop Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPushQueue Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::saveQueue Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::play index undefined Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::updateTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrackBlock Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::startPlaybackTimer Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:52 rivo volumio[3428]: info: [1742178232254] ControllerTidal::clearAddPlayTrack Mar 17 10:23:52 rivo volumio[3428]: info: Getting stream with soundQuality HI_RES Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand stop Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand stop took 102 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand stop took 31 milliseconds Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand clear Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:52 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:52 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand status took 10 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand clear took 8 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand status took 5 milliseconds Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES" Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:52 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:52 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:52 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:52 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:52 rivo volumio[3428]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 42ms Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:52 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:52 rivo volumio[3428]: error: updateQueue error: null Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:52 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 50ms Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 46 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES" took 46 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 11ms Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:52 rivo volumio[3428]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 17 10:23:52 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand play Mar 17 10:23:52 rivo volumio[3428]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 68ms Mar 17 10:23:52 rivo volumio[3428]: info: Mar 17 10:23:52 rivo volumio[3428]: ---------------------------- MPD announces system playlist update Mar 17 10:23:52 rivo volumio[3428]: info: Ignoring MPD Status Update Mar 17 10:23:52 rivo volumio[3428]: STREAMING PROXY: Handling url /?data=tidal://song/35980360&soundQuality=HI_RES Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 40ms Mar 17 10:23:52 rivo volumio[3428]: info: sendMpdCommand play took 35 milliseconds Mar 17 10:23:52 rivo volumio[3428]: info: ------------------------------ 32ms Mar 17 10:23:52 rivo volumio[3428]: info: Executing endpoint getStreamUrltidal Mar 17 10:23:52 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Mar 17 10:23:52 rivo volumio[3428]: info: MCU Signalled Playback Inactive Mar 17 10:23:52 rivo volumio[3428]: info: getStreamUrl took 507 milliseconds Mar 17 10:23:52 rivo volumio[3428]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEic1NDcwMTA2ZDM0ZGM1ODE5MjM0OWVkNjJiMzRlMjI4YV82MS5tcDQ/0.flac?Expires=1742181832&Signature=pUVKp-sIuT3UiztXaM9TY7-z-nSvzP90i8NpZWFI~DafbV6lGW5Fd2d78s1fej5hv-OHA-1gim-hmMgsuCG0Gc5RaK8d70qd7EHtX3T3Z4MRZ~ZLvgeJe1JQRIXTFFELX9Jt2WGE80rRX8nGnifxma7mT~TiEI00W4ItK~8Uq~5s-BtKlaGukRoAC7KljS5y-AfL5m8uOmhI5GNGE6ltV~uxLJsNjhP8k9LC~NW7nWowkZyHJcevaU1SevHJch-nX3V5U8J741cFW3UddT~dBmmWCk7vTR~fITcTYP1Mqvgt7iJSkHN6qJLVKA4~1mHg2DvwKrlPlB8Y~RBb7nfFaQ__&Key-Pair-Id=K14LZCZ9QUI4JL Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 17 10:23:53 rivo volumio[3428]: info: Discovery: Getting this device information Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioGetState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 17 10:23:53 rivo volumio[3428]: STREAMING PROXY: Response: 200, length: 21254099 Mar 17 10:23:53 rivo volumio[3428]: info: Mar 17 10:23:53 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:53 rivo kernel: aml_spdif_open Mar 17 10:23:53 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Mar 17 10:23:53 rivo kernel: set normal 512 fs /4 fs Mar 17 10:23:53 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 17 10:23:53 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 17 10:23:53 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Mar 17 10:23:53 rivo kernel: set normal 512 fs /4 fs Mar 17 10:23:53 rivo kernel: set spdifout clk:5644800, mpll:22579200 Mar 17 10:23:53 rivo kernel: get spdifout clk:5644797, mpll:22579186 Mar 17 10:23:53 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 17 10:23:53 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Mar 17 10:23:53 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Mar 17 10:23:53 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Mar 17 10:23:53 rivo volumio[3428]: info: Mar 17 10:23:53 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:53 rivo volumio[3428]: info: Mar 17 10:23:53 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand status took 8 milliseconds Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand status took 5 milliseconds Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:53 rivo volumio[3428]: info: Mar 17 10:23:53 rivo volumio[3428]: ---------------------------- MPD announces state update: player Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::getState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand status Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand status took 8 milliseconds Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 8 milliseconds Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 6 milliseconds Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:53 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:53 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"35980360&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:53 rivo volumio[3428]: verbose: CURRENT POSITION 3 Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus stop Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:53 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:53 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"35980360&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:53 rivo volumio[3428]: verbose: CURRENT POSITION 3 Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:53 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: ------------------------------ 55ms Mar 17 10:23:53 rivo volumio[3428]: info: ------------------------------ 79ms Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand status took 69 milliseconds Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 64 milliseconds Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseState Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:53 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:53 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"35980360&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:53 rivo volumio[3428]: verbose: CURRENT POSITION 3 Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:53 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: ------------------------------ 163ms Mar 17 10:23:53 rivo volumio[3428]: info: Signalling Playback active due to playback status change Mar 17 10:23:53 rivo volumio[3428]: info: sendMpdCommand playlistinfo took 141 milliseconds Mar 17 10:23:53 rivo volumio[3428]: verbose: ControllerMpd::parseTrackInfo Mar 17 10:23:53 rivo volumio[3428]: info: ControllerMpd::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::servicePushState Mar 17 10:23:53 rivo volumio[3428]: info: CorePlayQueue::getTrack 3 Mar 17 10:23:53 rivo volumio[3428]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":222,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"35980360&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35980360&soundQuality=HI_RES","trackType":"tidal"} Mar 17 10:23:53 rivo volumio[3428]: verbose: CURRENT POSITION 3 Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState stateService play Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::syncState currentStatus play Mar 17 10:23:53 rivo volumio[3428]: info: Received an update from plugin. extracting info from payload Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: CoreStateMachine::pushState Mar 17 10:23:53 rivo volumio[3428]: info: CoreCommandRouter::volumioPushState Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output update for this device Mar 17 10:23:53 rivo volumio[3428]: info: MRS: Pushing multiroomSync output Mar 17 10:23:53 rivo volumio[3428]: info: ------------------------------ 251ms Mar 17 10:23:53 rivo volumio[3428]: info: MCU Signalled Playback Active Mar 17 10:23:54 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Mar 17 10:23:54 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:54 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:54 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:54 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:54 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:23:54 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:23:56 rivo volumio[3428]: STREAMING PROXY: Client dropped request, destroying Mar 17 10:24:06 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 17 10:24:07 rivo volumio[3428]: info: browseTIDALUri took 961 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: Preload queue cleared Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210660 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210661 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210662 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210663 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210664 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210665 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210666 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210667 Mar 17 10:24:07 rivo volumio[3428]: info: Preloading song: tidal://song/210668 Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210660 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210661 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210662 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210663 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210664 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210665 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210666 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210667 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: Exploding uri tidal://song/210668 in service tidal Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 465 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: Executing endpoint getSimilarAlbums Mar 17 10:24:07 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 510 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 493 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:24:07 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:24:07 rivo volumio[3428]: info: Executing endpoint metavolumio Mar 17 10:24:07 rivo volumio[3428]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 535 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 482 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 488 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 532 milliseconds Mar 17 10:24:07 rivo volumio[3428]: info: explodeTIDALUri took 511 milliseconds Mar 17 10:24:08 rivo volumio[3428]: info: explodeTIDALUri took 550 milliseconds Mar 17 10:24:31 rivo volumio[3428]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 10:24:31 rivo volumio[3428]: Error: getaddrinfo ENOTFOUND lastfm.freetls.fastly.net Mar 17 10:24:31 rivo volumio[3428]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:71:26) { Mar 17 10:24:31 rivo volumio[3428]: errno: -3007, Mar 17 10:24:31 rivo volumio[3428]: code: 'ENOTFOUND', Mar 17 10:24:31 rivo volumio[3428]: syscall: 'getaddrinfo', Mar 17 10:24:31 rivo volumio[3428]: hostname: 'lastfm.freetls.fastly.net' Mar 17 10:24:31 rivo volumio[3428]: } Mar 17 10:24:31 rivo volumio[3428]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 17 10:24:32 rivo sudo[10582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-17 10:23 Mar 17 10:24:32 rivo sudo[10582]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"