-- Logs begin at Wed 2025-09-03 09:03:54 +07, end at Wed 2025-09-03 10:16:49 +07. -- Sep 03 10:15:02 rivoplus ntpd[16343]: Soliciting pool server 2401:5b60:0:2::21 Sep 03 10:15:03 rivoplus volumio[9016]: info: Preload queue cleared Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::ClearQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::stop Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::stPlaybackTimer Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::updateTrackBlock Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrackBlock Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 6 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 6 Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::serviceStop Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 6 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::serviceStop Sep 03 10:15:03 rivoplus volumio[9016]: info: [1756869303390] ControllerTidal::stop Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::stop Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::clearPlayQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::saveQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::addQueueItems Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::addQueueItems Sep 03 10:15:03 rivoplus volumio[9016]: info: Preload queue cleared Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/87252041 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/87252041 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/5119626 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/5119626 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/332071194 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/332071194 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/85809837 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/85809837 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/253992134 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/253992134 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/149391107 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/149391107 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/24577678 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/24577678 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/95441079 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/95441079 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/88674983 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/88674983 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/188575138 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/188575138 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/105769707 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/105769707 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/36069663 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/36069663 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/4523615 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/4523615 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/99219623 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/99219623 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/24140264 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/24140264 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/37987258 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/37987258 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/13418181 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/13418181 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/294563557 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/294563557 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/8755973 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/8755973 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/109813974 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/109813974 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/14336699 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/14336699 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/24606351 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/24606351 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/77699281 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/77699281 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/376346034 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/376346034 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/195928415 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/195928415 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/80666461 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/80666461 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/16944105 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/16944105 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/37082000 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/37082000 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/11343742 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/11343742 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/372765697 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/372765697 Sep 03 10:15:03 rivoplus volumio[9016]: info: Adding Item to queue: tidal://mymusic/tracks/az/325727423 Sep 03 10:15:03 rivoplus volumio[9016]: info: Using cached record of: tidal://mymusic/tracks/az/325727423 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::saveQueue Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::updateTrackBlock Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrackBlock Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPlay Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::play index 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::stop Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::play index undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::startPlaybackTimer Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetVisibleSources Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 03 10:15:03 rivoplus volumio[9016]: info: [1756869303448] ControllerTidal::clearAddPlayTrack Sep 03 10:15:03 rivoplus volumio[9016]: info: Getting stream with soundQuality HI_RES Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand stop took 79 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand stop took 22 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand clear Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand status took 10 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand clear took 9 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand status took 8 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand status took 6 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES" Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Sep 03 10:15:03 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:03 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:03 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:03 rivoplus volumio[9016]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 52ms Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 51ms Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: error: updateQueue error: null Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 55ms Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 52 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES" took 53 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 9ms Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 6ms Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 10:15:03 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand play Sep 03 10:15:03 rivoplus volumio[9016]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 74ms Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: info: Sep 03 10:15:03 rivoplus volumio[9016]: ---------------------------- MPD announces system playlist update Sep 03 10:15:03 rivoplus volumio[9016]: info: Ignoring MPD Status Update Sep 03 10:15:03 rivoplus volumio[9016]: STREAMING PROXY: Handling url /?data=tidal://song/325727423&soundQuality=HI_RES Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 34ms Sep 03 10:15:03 rivoplus volumio[9016]: info: sendMpdCommand play took 28 milliseconds Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 25ms Sep 03 10:15:03 rivoplus volumio[9016]: info: ------------------------------ 24ms Sep 03 10:15:03 rivoplus volumio[9016]: info: Executing endpoint getStreamUrltidal Sep 03 10:15:03 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 03 10:15:03 rivoplus volumio[9016]: info: MCU Signalled Playback Inactive Sep 03 10:15:04 rivoplus volumio[9016]: info: getStreamUrl took 636 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxOGUxMDNlMWZlMDYyMzNiM2ZiOGViYWJlYzIzYjM4Y182MS5tcDQ/0.flac?token=1756872904~M2JkN2QwMmY2N2UzMmI1MDVhMGE4YjcwZDliOTViZGNiNDk2ZWZiOQ== Sep 03 10:15:04 rivoplus volumio[9016]: STREAMING PROXY: Response: 200, length: 29167106 Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 18 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 20 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 19 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 4 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus stop Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 31ms Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: info: Sep 03 10:15:04 rivoplus volumio[9016]: ---------------------------- MPD announces state update: player Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::getState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand status Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 13 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 7 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand status took 2 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseState Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus play Sep 03 10:15:04 rivoplus volumio[9016]: info: Received an update from plugin. extracting info from payload Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus ntpd[16343]: Soliciting pool server 115.165.161.155 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus play Sep 03 10:15:04 rivoplus volumio[9016]: info: Received an update from plugin. extracting info from payload Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1166,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"189 Kbps","isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus play Sep 03 10:15:04 rivoplus volumio[9016]: info: Received an update from plugin. extracting info from payload Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 140ms Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 140ms Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 128ms Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 109 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: info: sendMpdCommand playlistinfo took 110 milliseconds Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: verbose: ControllerMpd::parseTrackInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"191 Kbps","isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus play Sep 03 10:15:04 rivoplus volumio[9016]: info: Received an update from plugin. extracting info from payload Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: ControllerMpd::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::servicePushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CorePlayQueue::getTrack 30 Sep 03 10:15:04 rivoplus volumio[9016]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":279,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"190 Kbps","isStreaming":false,"title":"325727423&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727423&soundQuality=HI_RES","trackType":"tidal"} Sep 03 10:15:04 rivoplus volumio[9016]: verbose: CURRENT POSITION 30 Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState stateService play Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::syncState currentStatus play Sep 03 10:15:04 rivoplus volumio[9016]: info: Received an update from plugin. extracting info from payload Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreStateMachine::pushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioPushState Sep 03 10:15:04 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output update for this device Sep 03 10:15:04 rivoplus volumio[9016]: info: MRS: Pushing multiroomSync output Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 197ms Sep 03 10:15:04 rivoplus volumio[9016]: info: ------------------------------ 194ms Sep 03 10:15:04 rivoplus volumio[9016]: info: Signalling Playback active due to playback status change Sep 03 10:15:04 rivoplus volumio[9016]: info: MCU Signalled Playback Active Sep 03 10:15:05 rivoplus volumio[9016]: info: Executing endpoint metavolumio Sep 03 10:15:05 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 10:15:05 rivoplus volumio[9016]: info: Executing endpoint metavolumio Sep 03 10:15:05 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 10:15:05 rivoplus volumio[9016]: info: Executing endpoint metavolumio Sep 03 10:15:05 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 10:15:06 rivoplus volumio[9016]: STREAMING PROXY: Client dropped request, destroying Sep 03 10:15:08 rivoplus ntpd[16343]: Soliciting pool server 103.184.124.254 Sep 03 10:15:09 rivoplus ntpd[16343]: Soliciting pool server 103.184.124.254 Sep 03 10:15:11 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 10:15:11 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 10:15:11 rivoplus volumio[9016]: info: Discovery: Getting this device information Sep 03 10:15:11 rivoplus volumio[9016]: info: CoreCommandRouter::volumioGetState Sep 03 10:15:11 rivoplus volumio[9016]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 10:15:12 rivoplus volumio[9016]: error: Failed request for metavolumio API Sep 03 10:16:09 rivoplus ntpd[16343]: Soliciting pool server 2400:6760:0:200::254 Sep 03 10:16:10 rivoplus ntpd[16343]: Soliciting pool server 115.165.161.155 Sep 03 10:16:14 rivoplus ntpd[16343]: Soliciting pool server 115.165.161.155 Sep 03 10:16:15 rivoplus ntpd[16343]: Soliciting pool server 115.165.161.155 Sep 03 10:16:49 rivoplus volumio[9016]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 10:16:49 rivoplus volumio[9016]: Error: connect ETIMEDOUT 151.101.130.79:443 Sep 03 10:16:49 rivoplus volumio[9016]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Sep 03 10:16:49 rivoplus volumio[9016]: errno: -110, Sep 03 10:16:49 rivoplus volumio[9016]: code: 'ETIMEDOUT', Sep 03 10:16:49 rivoplus volumio[9016]: syscall: 'connect', Sep 03 10:16:49 rivoplus volumio[9016]: address: '151.101.130.79', Sep 03 10:16:49 rivoplus volumio[9016]: port: 443 Sep 03 10:16:49 rivoplus volumio[9016]: } Sep 03 10:16:49 rivoplus volumio[9016]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 10:16:49 rivoplus sudo[18304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-03 10:15 Sep 03 10:16:49 rivoplus sudo[18304]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:23:19 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ca35d8983c8e34dfa9cca80071cf9105"