-- Logs begin at Wed 2025-04-30 15:15:09 CEST, end at Wed 2025-04-30 15:26:23 CEST. -- Apr 30 15:25:05 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:05 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:06 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:06 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:11 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:11 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:13 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:13 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:19 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:19 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:22 rivoplus systemd-udevd[2589]: sda: Worker [5842] processing SEQNUM=6442 is taking a long time Apr 30 15:25:23 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 15:25:28 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 Apr 30 15:25:28 rivoplus volumio[3200]: info: Preloading song: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 in service upnp_browser Apr 30 15:25:28 rivoplus volumio[3200]: info: Exploding uri upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 in service upnp_browser Apr 30 15:25:37 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::ClearQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::stop Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::clearPlayQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::addQueueItems Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::addQueueItems Apr 30 15:25:37 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::updateTrackBlock Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::getTrackBlock Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPlay Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::play index 7 Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::addQueueItems Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::addQueueItems Apr 30 15:25:37 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 Apr 30 15:25:37 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 Apr 30 15:25:37 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::stop Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::play index undefined Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::updateTrackBlock Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::getTrackBlock Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:37 rivoplus volumio[3200]: info: CoreStateMachine::startPlaybackTimer Apr 30 15:25:37 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:37 rivoplus volumio[3200]: info: [1746019537967] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 15:25:37 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 15:25:37 rivoplus volumio[3200]: info: sendMpdCommand stop took 8 milliseconds Apr 30 15:25:37 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 15:25:37 rivoplus volumio[3200]: info: Apr 30 15:25:37 rivoplus volumio[3200]: ---------------------------- MPD announces system playlist update Apr 30 15:25:37 rivoplus volumio[3200]: info: Ignoring MPD Status Update Apr 30 15:25:37 rivoplus volumio[3200]: info: sendMpdCommand clear took 2 milliseconds Apr 30 15:25:37 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" Apr 30 15:25:37 rivoplus volumio[3200]: error: updateQueue error: null Apr 30 15:25:37 rivoplus volumio[3200]: info: ------------------------------ 4ms Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" Apr 30 15:25:38 rivoplus volumio[3200]: info: Apr 30 15:25:38 rivoplus volumio[3200]: ---------------------------- MPD announces system playlist update Apr 30 15:25:38 rivoplus volumio[3200]: info: Ignoring MPD Status Update Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand add "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" took 2 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand play Apr 30 15:25:38 rivoplus volumio[3200]: info: ------------------------------ 3ms Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand play took 2 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: info: Apr 30 15:25:38 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:25:38 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:25:38 rivoplus volumio[3200]: info: Apr 30 15:25:38 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand status took 104 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand status took 4 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:25:38 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:38 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:25:38 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService play Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus stop Apr 30 15:25:38 rivoplus volumio[3200]: info: ------------------------------ 116ms Apr 30 15:25:38 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 30 15:25:38 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:25:38 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:38 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1219,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:25:38 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService play Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus play Apr 30 15:25:38 rivoplus volumio[3200]: info: Received an update from plugin. extracting info from payload Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:25:38 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:25:38 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:25:38 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:25:38 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:25:38 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:25:38 rivoplus volumio[3200]: info: ------------------------------ 69ms Apr 30 15:25:38 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:38 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:38 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:38 rivoplus volumio[3200]: info: Signalling Playback active due to playback status change Apr 30 15:25:38 rivoplus volumio[3200]: info: Signalling Playback active due to playback status change Apr 30 15:25:38 rivoplus volumio[3200]: info: MCU Signalled Playback Active Apr 30 15:25:40 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:25:40 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPause Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::pause Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::stPlaybackTimer Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::servicePause Apr 30 15:25:41 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreCommandRouter::servicePause Apr 30 15:25:41 rivoplus volumio[3200]: info: [1746019541572] ControllerUPNPBrowser::pause Apr 30 15:25:41 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand pause Apr 30 15:25:41 rivoplus volumio[3200]: info: Apr 30 15:25:41 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:25:41 rivoplus volumio[3200]: info: sendMpdCommand pause took 3 milliseconds Apr 30 15:25:41 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:25:41 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:25:41 rivoplus volumio[3200]: info: sendMpdCommand status took 1 milliseconds Apr 30 15:25:41 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:25:41 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:25:41 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 30 15:25:41 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:25:41 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:25:41 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:41 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4708,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:25:41 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService pause Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus pause Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:25:41 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:25:41 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:25:41 rivoplus volumio[3200]: info: CoreStateMachine::stPlaybackTimer Apr 30 15:25:41 rivoplus volumio[3200]: info: ------------------------------ 28ms Apr 30 15:25:41 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:41 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:41 rivoplus volumio[3200]: info: MCU Signalled Playback Inactive Apr 30 15:25:43 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:25:43 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:25:44 rivoplus volumio[3200]: error: Failed request for metavolumio API Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPlay Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::play index undefined Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:25:49 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::startPlaybackTimer Apr 30 15:25:49 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:49 rivoplus volumio[3200]: info: [1746019549330] ControllerUPNPBrowser::resume Apr 30 15:25:49 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand play Apr 30 15:25:49 rivoplus volumio[3200]: info: Apr 30 15:25:49 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:25:49 rivoplus volumio[3200]: info: sendMpdCommand play took 39 milliseconds Apr 30 15:25:49 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:25:49 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:25:49 rivoplus volumio[3200]: info: sendMpdCommand status took 6 milliseconds Apr 30 15:25:49 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:25:49 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:25:49 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 30 15:25:49 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:25:49 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:25:49 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:49 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5948,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:25:49 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService play Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus pause Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:25:49 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:25:49 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:25:49 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:25:49 rivoplus volumio[3200]: info: ------------------------------ 27ms Apr 30 15:25:49 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:49 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreCommandRouter::volumioGetQueue Apr 30 15:25:49 rivoplus volumio[3200]: info: CoreStateMachine::getQueue Apr 30 15:25:49 rivoplus volumio[3200]: info: CorePlayQueue::getQueue Apr 30 15:25:49 rivoplus volumio[3200]: info: Signalling Playback active due to playback status change Apr 30 15:25:49 rivoplus volumio[3200]: info: MCU Signalled Playback Active Apr 30 15:25:51 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:25:51 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:25:51 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:25:51 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:25:51 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:25:51 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:26:00 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::ClearQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::stop Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::stPlaybackTimer Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::updateTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::serviceStop Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::serviceStop Apr 30 15:26:00 rivoplus volumio[3200]: info: [1746019560172] ControllerUPNPBrowser::stop Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::clearPlayQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::addQueueItems Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::addQueueItems Apr 30 15:26:00 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i24943 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i29211 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20974 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20078 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20386 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i4285 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i11953 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i21111 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::updateTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPlay Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::play index 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::addQueueItems Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::addQueueItems Apr 30 15:26:00 rivoplus volumio[3200]: info: Preload queue cleared Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i10622 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i32199 Apr 30 15:26:00 rivoplus volumio[3200]: info: Adding Item to queue: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 Apr 30 15:26:00 rivoplus volumio[3200]: info: Using cached record of: upnp/http://192.168.1.23:9791/05addf09-e516-42f2-89a1-369c99d67c14/upnp.org-ContentDirectory-1/control@0$folders$f1994$f2011$f2016$*i20079 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::stop Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::saveQueue Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::play index undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::updateTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrackBlock Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::startPlaybackTimer Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: [1746019560233] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Apr 30 15:26:00 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand stop took 108 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand stop took 48 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 15:26:00 rivoplus volumio[3200]: info: Apr 30 15:26:00 rivoplus volumio[3200]: ---------------------------- MPD announces system playlist update Apr 30 15:26:00 rivoplus volumio[3200]: info: Ignoring MPD Status Update Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand status took 4 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand clear took 3 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" Apr 30 15:26:00 rivoplus volumio[3200]: error: updateQueue error: null Apr 30 15:26:00 rivoplus volumio[3200]: info: ------------------------------ 5ms Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:26:00 rivoplus volumio[3200]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 30 15:26:00 rivoplus volumio[3200]: info: ------------------------------ 12ms Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" Apr 30 15:26:00 rivoplus volumio[3200]: info: Apr 30 15:26:00 rivoplus volumio[3200]: ---------------------------- MPD announces system playlist update Apr 30 15:26:00 rivoplus volumio[3200]: info: Ignoring MPD Status Update Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand add "http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav" took 2 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand play Apr 30 15:26:00 rivoplus volumio[3200]: info: ------------------------------ 3ms Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand play took 2 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: MCU Signalled Playback Inactive Apr 30 15:26:00 rivoplus volumio[3200]: info: Apr 30 15:26:00 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:26:00 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:26:00 rivoplus volumio[3200]: info: Apr 30 15:26:00 rivoplus volumio[3200]: ---------------------------- MPD announces state update: player Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand status took 45 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: ControllerMpd::getState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand status Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand status took 12 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseState Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:26:00 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:26:00 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService play Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus stop Apr 30 15:26:00 rivoplus volumio[3200]: info: ------------------------------ 88ms Apr 30 15:26:00 rivoplus volumio[3200]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 30 15:26:00 rivoplus volumio[3200]: verbose: ControllerMpd::parseTrackInfo Apr 30 15:26:00 rivoplus volumio[3200]: info: ControllerMpd::pushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::servicePushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CorePlayQueue::getTrack 7 Apr 30 15:26:00 rivoplus volumio[3200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1219,"duration":509,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"08*20Nature*20Boy.wav","artist":null,"album":null,"uri":"http://192.168.1.23:9790/minimserver/*/MUSICA/ITALIAN*20JAZZ/ENRICO*20RAVA/*5b2003*5d*20Full*20Of*20Life/08*20Nature*20Boy.wav","trackType":"wav"} Apr 30 15:26:00 rivoplus volumio[3200]: verbose: CURRENT POSITION 7 Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::syncState stateService play Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::syncState currentStatus play Apr 30 15:26:00 rivoplus volumio[3200]: info: Received an update from plugin. extracting info from payload Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreStateMachine::pushState Apr 30 15:26:00 rivoplus volumio[3200]: info: CoreCommandRouter::volumioPushState Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output update for this device Apr 30 15:26:00 rivoplus volumio[3200]: info: MRS: Pushing multiroomSync output Apr 30 15:26:00 rivoplus volumio[3200]: info: ------------------------------ 161ms Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Updating RAAT Signal Path Apr 30 15:26:00 rivoplus volumio[3200]: info: Signalling Playback active due to playback status change Apr 30 15:26:00 rivoplus volumio[3200]: info: Signalling Playback active due to playback status change Apr 30 15:26:00 rivoplus volumio[3200]: info: MCU Signalled Playback Active Apr 30 15:26:02 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:26:02 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:26:03 rivoplus volumio[3200]: error: Failed request for metavolumio API Apr 30 15:26:12 rivoplus volumio[3200]: info: CoreCommandRouter::volumioGetState Apr 30 15:26:15 rivoplus volumio[3200]: info: Executing endpoint metavolumio Apr 30 15:26:15 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: Retrieving Cloud Streaming UI Apr 30 15:26:16 rivoplus volumio[3200]: info: Getting Tidal Cloud Configuration Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: Getting Qobuz Cloud Configuration Apr 30 15:26:16 rivoplus volumio[3200]: info: Asking plugin for UI Config Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: Getting Spotify Cloud Configuration Apr 30 15:26:16 rivoplus volumio[3200]: info: Asking plugin for UI Config Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: Saving Spotify Acccount Apr 30 15:26:16 rivoplus volumio[3200]: info: Got it Apr 30 15:26:16 rivoplus volumio[3200]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 30 15:26:16 rivoplus volumio[3200]: info: Got Tidal Cloud Configuration Apr 30 15:26:16 rivoplus volumio[3200]: info: Got it Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::volumioGetBrowseSources Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::volumioGetBrowseSources Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::volumioGetBrowseSources Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 30 15:26:16 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 30 15:26:17 rivoplus ntpd[4099]: 93.94.88.50 local addr 192.168.1.73 -> Apr 30 15:26:19 rivoplus volumio[3200]: info: Disabling MyMusic plugin upnp Apr 30 15:26:19 rivoplus sudo[6164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 30 15:26:19 rivoplus sudo[6164]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 15:26:19 rivoplus volumio[3200]: error: Upnp client error: Error: This socket has been ended by the other party Apr 30 15:26:19 rivoplus systemd[1]: Stopping UPnP Renderer front-end to MPD... Apr 30 15:26:19 rivoplus volumio[3200]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 30 15:26:20 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 30 15:26:22 rivoplus volumio[3200]: info: Enabling MyMusic plugin upnp Apr 30 15:26:22 rivoplus volumio[3200]: info: Enabling plugin upnp Apr 30 15:26:22 rivoplus volumio[3200]: info: Loading plugin "upnp"... Apr 30 15:26:22 rivoplus volumio[3200]: info: [1746019582606] Starting Upmpd Daemon Apr 30 15:26:22 rivoplus volumio[3200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 30 15:26:22 rivoplus volumio[3200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 15:26:22 rivoplus volumio[3200]: Error: listen EADDRINUSE: address already in use :::6599 Apr 30 15:26:22 rivoplus volumio[3200]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Apr 30 15:26:22 rivoplus volumio[3200]: at listenInCluster (net.js:1379:12) Apr 30 15:26:22 rivoplus volumio[3200]: at Server.listen (net.js:1465:7) Apr 30 15:26:22 rivoplus volumio[3200]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 30 15:26:22 rivoplus volumio[3200]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 30 15:26:22 rivoplus volumio[3200]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 30 15:26:22 rivoplus volumio[3200]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 30 15:26:22 rivoplus volumio[3200]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Apr 30 15:26:22 rivoplus volumio[3200]: code: 'EADDRINUSE', Apr 30 15:26:22 rivoplus volumio[3200]: errno: -98, Apr 30 15:26:22 rivoplus volumio[3200]: syscall: 'listen', Apr 30 15:26:22 rivoplus volumio[3200]: address: '::', Apr 30 15:26:22 rivoplus volumio[3200]: port: 6599 Apr 30 15:26:22 rivoplus volumio[3200]: } Apr 30 15:26:22 rivoplus volumio[3200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 15:26:23 rivoplus sudo[6175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-30 15:25 Apr 30 15:26:23 rivoplus sudo[6175]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:42:11 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="4f5519a96ae5ba7dcfda362cc37343d4"