-- Logs begin at Mon 2025-10-27 16:11:54 EET, end at Tue 2025-10-28 00:10:55 EET. -- Oct 28 00:09:02 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:03 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:05 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 00:09:05 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 00:09:05 rivoplus volumio[3128]: info: Discovery: Getting this device information Oct 28 00:09:05 rivoplus volumio[3128]: info: CoreCommandRouter::volumioGetState Oct 28 00:09:05 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 00:09:06 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:07 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:10 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:11 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:14 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:15 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:18 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:19 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:22 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:23 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:26 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:27 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:30 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:31 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:34 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:35 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 00:09:35 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 00:09:35 rivoplus volumio[3128]: info: Discovery: Getting this device information Oct 28 00:09:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioGetState Oct 28 00:09:35 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 00:09:35 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:38 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:39 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:42 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:43 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:46 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:47 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:50 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:51 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:54 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:55 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:58 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:09:59 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:02 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:03 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:04 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 00:10:04 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 00:10:04 rivoplus volumio[3128]: info: Discovery: Getting this device information Oct 28 00:10:04 rivoplus volumio[3128]: info: CoreCommandRouter::volumioGetState Oct 28 00:10:04 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 00:10:06 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:07 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:10 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:11 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:14 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 28 00:10:14 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:14 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$1$2$0 Oct 28 00:10:14 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$1$2$0 in service upnp_browser Oct 28 00:10:14 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:14 rivoplus volumio[3128]: info: No valid Plugin REST Endpoint: getSimilarAlbums Oct 28 00:10:15 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:18 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:19 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:22 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:23 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:24 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 28 00:10:24 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:24 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:24 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:24 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:24 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:24 rivoplus volumio[3128]: info: Preloading song: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:24 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 in service upnp_browser Oct 28 00:10:24 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 in service upnp_browser Oct 28 00:10:24 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 in service upnp_browser Oct 28 00:10:24 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 in service upnp_browser Oct 28 00:10:25 rivoplus volumio[3128]: info: Exploding uri upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 in service upnp_browser Oct 28 00:10:26 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::ClearQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::clearPlayQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:26 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 Oct 28 00:10:26 rivoplus volumio[3128]: info: Exploding uri upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 in service upnp_browser Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:26 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPlay Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::play index 1 Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:26 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:26 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:26 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:26 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:26 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:26 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::play index undefined Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreStateMachine::startPlaybackTimer Oct 28 00:10:26 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:26 rivoplus volumio[3128]: info: [1761603026766] ControllerUPNPBrowser::clearAddPlayTrack Oct 28 00:10:26 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 00:10:26 rivoplus volumio[3128]: info: sendMpdCommand stop took 4 milliseconds Oct 28 00:10:26 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 00:10:26 rivoplus volumio[3128]: info: Oct 28 00:10:26 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:26 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:26 rivoplus volumio[3128]: info: sendMpdCommand clear took 1 milliseconds Oct 28 00:10:26 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:26 rivoplus volumio[3128]: info: Oct 28 00:10:26 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:26 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:26 rivoplus volumio[3128]: info: Oct 28 00:10:26 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:26 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:26 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:26 rivoplus volumio[3128]: info: ------------------------------ 8ms Oct 28 00:10:26 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:27 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:30 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:31 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:33 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::ClearQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::clearPlayQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:33 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPlay Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::play index 1 Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:33 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:33 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:33 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::play index undefined Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:33 rivoplus volumio[3128]: info: CoreStateMachine::startPlaybackTimer Oct 28 00:10:33 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:33 rivoplus volumio[3128]: info: [1761603033425] ControllerUPNPBrowser::clearAddPlayTrack Oct 28 00:10:33 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 00:10:34 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:34 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 00:10:34 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 00:10:34 rivoplus volumio[3128]: info: Discovery: Getting this device information Oct 28 00:10:34 rivoplus volumio[3128]: info: CoreCommandRouter::volumioGetState Oct 28 00:10:34 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:34 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 00:10:35 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::ClearQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::clearPlayQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:35 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/folder/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$5 Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$0 Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPlay Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::play index 1 Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::addQueueItems Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::addQueueItems Oct 28 00:10:35 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$1 Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$2 Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$3 Oct 28 00:10:35 rivoplus volumio[3128]: info: Adding Item to queue: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:35 rivoplus volumio[3128]: info: Using cached record of: upnp/http://192.168.1.47:8200/ctl/ContentDir@64$3$2$3$8$4 Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::stop Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::saveQueue Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::play index undefined Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::updateTrackBlock Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::getTrackBlock Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreStateMachine::startPlaybackTimer Oct 28 00:10:35 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:35 rivoplus volumio[3128]: info: [1761603035094] ControllerUPNPBrowser::clearAddPlayTrack Oct 28 00:10:35 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 00:10:35 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 10312ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 10311ms Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand stop took 3663 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand stop took 1994 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" took 72 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand play Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand clear took 67 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand clear took 67 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 65ms Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand play took 63 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 63ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 62ms Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 11ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: error: updateQueue error: null Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 19ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 16ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" took 12 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand add "http://192.168.1.47:8200/MediaItems/31304.dsd" took 3 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand play Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 11ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 11ms Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand play took 10 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand play took 9 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 8ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 15ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces system playlist update Oct 28 00:10:37 rivoplus volumio[3128]: info: Ignoring MPD Status Update Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 8ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 10ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 111 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 111 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 109 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 3 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus stop Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 125ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: info: Oct 28 00:10:37 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 4 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus play Oct 28 00:10:37 rivoplus volumio[3128]: info: Received an update from plugin. extracting info from payload Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus play Oct 28 00:10:37 rivoplus volumio[3128]: info: Received an update from plugin. extracting info from payload Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":31,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus play Oct 28 00:10:37 rivoplus volumio[3128]: info: Received an update from plugin. extracting info from payload Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 187ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 186ms Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 83ms Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand status took 66 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 59 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":131,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus play Oct 28 00:10:37 rivoplus volumio[3128]: info: Received an update from plugin. extracting info from payload Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 98ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 63 milliseconds Oct 28 00:10:37 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:37 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:37 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService play Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus play Oct 28 00:10:37 rivoplus volumio[3128]: info: Received an update from plugin. extracting info from payload Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:37 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:37 rivoplus volumio[3128]: info: ------------------------------ 163ms Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: Signalling Playback active due to playback status change Oct 28 00:10:37 rivoplus volumio[3128]: info: MCU Signalled Playback Active Oct 28 00:10:38 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::stPlaybackTimer Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::servicePause Oct 28 00:10:39 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::servicePause Oct 28 00:10:39 rivoplus volumio[3128]: info: [1761603039795] ControllerUPNPBrowser::pause Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand pause Oct 28 00:10:39 rivoplus volumio[3128]: info: Oct 28 00:10:39 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand pause took 4 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:39 rivoplus volumio[3128]: info: Oct 28 00:10:39 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:39 rivoplus volumio[3128]: info: Oct 28 00:10:39 rivoplus volumio[3128]: ---------------------------- MPD announces state update: player Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::getState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand status Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand status took 5 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand status took 3 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand status took 2 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseState Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:39 rivoplus volumio[3128]: verbose: ControllerMpd::parseTrackInfo Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:39 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2962,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:39 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::stPlaybackTimer Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:39 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2962,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:39 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::stPlaybackTimer Oct 28 00:10:39 rivoplus volumio[3128]: info: ControllerMpd::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::servicePushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CorePlayQueue::getTrack 1 Oct 28 00:10:39 rivoplus volumio[3128]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2962,"duration":952,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"31304.dsd","artist":null,"album":null,"uri":"http://192.168.1.47:8200/MediaItems/31304.dsd","trackType":"dsd"} Oct 28 00:10:39 rivoplus volumio[3128]: verbose: CURRENT POSITION 1 Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState stateService pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::syncState currentStatus pause Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::pushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreCommandRouter::volumioPushState Oct 28 00:10:39 rivoplus volumio[3128]: info: CoreStateMachine::stPlaybackTimer Oct 28 00:10:39 rivoplus volumio[3128]: info: ------------------------------ 39ms Oct 28 00:10:39 rivoplus volumio[3128]: info: ------------------------------ 38ms Oct 28 00:10:39 rivoplus volumio[3128]: info: ------------------------------ 37ms Oct 28 00:10:39 rivoplus volumio[3128]: info: MCU Signalled Playback Inactive Oct 28 00:10:42 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:43 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:46 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:47 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:48 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 28 00:10:48 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:50 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:51 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 28 00:10:52 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 28 00:10:52 rivoplus volumio[3128]: info: Preload queue cleared Oct 28 00:10:54 rivoplus volumio[3128]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 28 00:10:54 rivoplus volumio[3128]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 00:10:54 rivoplus volumio[3128]: TypeError: Cannot read property 'length' of undefined Oct 28 00:10:54 rivoplus volumio[3128]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 28 00:10:54 rivoplus volumio[3128]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 28 00:10:54 rivoplus volumio[3128]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 28 00:10:54 rivoplus volumio[3128]: at Parser.emit (events.js:400:28) Oct 28 00:10:54 rivoplus volumio[3128]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 28 00:10:54 rivoplus volumio[3128]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 28 00:10:54 rivoplus volumio[3128]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 28 00:10:54 rivoplus volumio[3128]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 28 00:10:54 rivoplus volumio[3128]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 28 00:10:54 rivoplus volumio[3128]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 28 00:10:54 rivoplus volumio[3128]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 28 00:10:54 rivoplus volumio[3128]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 28 00:10:54 rivoplus volumio[3128]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 28 00:10:54 rivoplus volumio[3128]: at IncomingMessage.emit (events.js:412:35) Oct 28 00:10:54 rivoplus volumio[3128]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 28 00:10:54 rivoplus volumio[3128]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 28 00:10:54 rivoplus volumio[3128]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 00:10:55 rivoplus sudo[14631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-28 00:09 Oct 28 00:10:55 rivoplus sudo[14631]: 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"