-- Logs begin at Wed 2025-04-30 13:01:46 CST, end at Wed 2025-04-30 17:10:21 CST. -- Apr 30 17:09:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 17:09:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 17:09:15 smsl-n100 volumio[1079]: info: Discovery: Getting this device information Apr 30 17:09:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioGetState Apr 30 17:09:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 17:09:25 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:25 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:25 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:25 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:32 smsl-n100 ntpd[968]: Soliciting pool server 47.254.196.78 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:34 smsl-n100 volumio[1079]: info: Preloading song: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 in service upnp_browser Apr 30 17:09:35 smsl-n100 volumio[1079]: info: Exploding uri upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 in service upnp_browser Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Executing endpoint getSimilarAlbums Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::ClearQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::stPlaybackTimer Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 8 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:38 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:38 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::serviceStop Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 8 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::serviceStop Apr 30 17:09:38 smsl-n100 volumio[1079]: info: [1746004178923] ControllerUPNPBrowser::stop Apr 30 17:09:38 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::clearPlayQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPlay Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::play index 3 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:38 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::play index undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::startPlaybackTimer Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: [1746004179022] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Updating RAAT Signal Path Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Apr 30 17:09:39 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 125 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 30 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Apr 30 17:09:39 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand status took 10 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand clear took 8 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.35:16000/audio/308721.wav" Apr 30 17:09:39 smsl-n100 volumio[1079]: error: updateQueue error: null Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ------------------------------ 15ms Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ------------------------------ 31ms Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.35:16000/audio/308721.wav" Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Apr 30 17:09:39 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand add "http://192.168.1.35:16000/audio/308721.wav" took 4 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand play Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ------------------------------ 8ms Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand play took 5 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: info: VolumeController::SetAlsaVolume0 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Updating RAAT Signal Path Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Apr 30 17:09:39 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:39 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand status took 423 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Apr 30 17:09:39 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":236,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308721.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308721.wav","trackType":"wav"} Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus stop Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ------------------------------ 469ms Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand status took 23 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":236,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308721.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308721.wav","trackType":"wav"} Apr 30 17:09:39 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 3 Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus play Apr 30 17:09:39 smsl-n100 volumio[1079]: info: Received an update from plugin. extracting info from payload Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:39 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:40 smsl-n100 volumio[1079]: info: ------------------------------ 188ms Apr 30 17:09:40 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:40 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:40 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:40 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::ClearQueue Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::stPlaybackTimer Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:41 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:41 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::serviceStop Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 3 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::serviceStop Apr 30 17:09:41 smsl-n100 volumio[1079]: info: [1746004181972] ControllerUPNPBrowser::stop Apr 30 17:09:41 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::clearPlayQueue Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:41 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:41 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPlay Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::play index 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::play index undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::startPlaybackTimer Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: [1746004182091] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Apr 30 17:09:42 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 151 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 36 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Apr 30 17:09:42 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand status took 21 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand clear took 19 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.35:16000/audio/308722.wav" Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Executing endpoint metavolumio Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 30 17:09:42 smsl-n100 volumio[1079]: error: updateQueue error: null Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ------------------------------ 27ms Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 22 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:42 smsl-n100 volumio[1079]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ------------------------------ 53ms Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:42 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:42 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.35:16000/audio/308722.wav" Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Apr 30 17:09:42 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand add "http://192.168.1.35:16000/audio/308722.wav" took 5 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand play Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ------------------------------ 8ms Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand play took 4 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Apr 30 17:09:42 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Apr 30 17:09:42 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand status took 22 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand status took 38 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 34 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308722.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308722.wav","trackType":"wav"} Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus stop Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ------------------------------ 168ms Apr 30 17:09:42 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 80 milliseconds Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308722.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308722.wav","trackType":"wav"} Apr 30 17:09:42 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 4 Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus play Apr 30 17:09:42 smsl-n100 volumio[1079]: info: Received an update from plugin. extracting info from payload Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:42 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:42 smsl-n100 volumio[1079]: info: ------------------------------ 475ms Apr 30 17:09:43 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:43 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:43 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:43 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:43 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:43 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:43 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:43 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:43 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::ClearQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::stPlaybackTimer Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:45 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:45 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::serviceStop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 4 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::serviceStop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: [1746004185810] ControllerUPNPBrowser::stop Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::clearPlayQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPlay Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::play index 5 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::play index undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::startPlaybackTimer Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: [1746004185906] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Apr 30 17:09:45 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:45 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 125 milliseconds Apr 30 17:09:45 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:45 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 31 milliseconds Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Apr 30 17:09:45 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:45 smsl-n100 volumio[1079]: info: sendMpdCommand status took 8 milliseconds Apr 30 17:09:45 smsl-n100 volumio[1079]: info: sendMpdCommand clear took 6 milliseconds Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.35:16000/audio/308723.wav" Apr 30 17:09:45 smsl-n100 volumio[1079]: error: updateQueue error: null Apr 30 17:09:45 smsl-n100 volumio[1079]: info: ------------------------------ 14ms Apr 30 17:09:45 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 30 17:09:45 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:45 smsl-n100 volumio[1079]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: info: ------------------------------ 29ms Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 17:09:45 smsl-n100 volumio[1079]: info: Discovery: Getting this device information Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioGetState Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:45 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:45 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:45 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:45 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:45 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:46 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.35:16000/audio/308723.wav" Apr 30 17:09:46 smsl-n100 volumio[1079]: info: Apr 30 17:09:46 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:46 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand add "http://192.168.1.35:16000/audio/308723.wav" took 4 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand play Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ------------------------------ 12ms Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand play took 8 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: info: Apr 30 17:09:46 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:46 smsl-n100 volumio[1079]: info: Apr 30 17:09:46 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand status took 26 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand status took 63 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 28 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":160,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308723.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308723.wav","trackType":"wav"} Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 5 Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus stop Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ------------------------------ 150ms Apr 30 17:09:46 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 29 milliseconds Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308723.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308723.wav","trackType":"wav"} Apr 30 17:09:46 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 5 Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus play Apr 30 17:09:46 smsl-n100 volumio[1079]: info: Received an update from plugin. extracting info from payload Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:46 smsl-n100 volumio[1079]: info: ------------------------------ 241ms Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:46 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:46 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:46 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:46 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:46 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::ClearQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::stPlaybackTimer Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:50 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:50 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::serviceStop Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 5 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::serviceStop Apr 30 17:09:50 smsl-n100 volumio[1079]: info: [1746004190883] ControllerUPNPBrowser::stop Apr 30 17:09:50 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::clearPlayQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308718 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308719 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308720 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308721 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308722 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308723 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308724 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308725 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308726 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308727 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308728 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308729 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308730 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308731 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPlay Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::play index 13 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::addQueueItems Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::addQueueItems Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Adding Item to queue: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: Using cached record of: upnp/http://192.168.1.35:16000/ContentDirectory/5F9EC1B3-ED59-79BB-0010-00142D4F5023/control.xml@0:med.2:album:alb.18437:trk.308732 Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::stop Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::saveQueue Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::play index undefined Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CoreStateMachine::updateTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrackBlock Apr 30 17:09:50 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::startPlaybackTimer Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: info: [1746004191001] ControllerUPNPBrowser::clearAddPlayTrack Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Apr 30 17:09:51 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 146 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand stop took 32 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand clear Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Apr 30 17:09:51 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand status took 9 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand clear took 7 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.35:16000/audio/308731.wav" Apr 30 17:09:51 smsl-n100 volumio[1079]: error: updateQueue error: null Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ------------------------------ 12ms Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ------------------------------ 27ms Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.35:16000/audio/308731.wav" Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Apr 30 17:09:51 smsl-n100 volumio[1079]: ---------------------------- MPD announces system playlist update Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Ignoring MPD Status Update Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand add "http://192.168.1.35:16000/audio/308731.wav" took 4 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand play Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ------------------------------ 8ms Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand play took 5 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Apr 30 17:09:51 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Apr 30 17:09:51 smsl-n100 volumio[1079]: ---------------------------- MPD announces state update: player Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ControllerMpd::getState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand status Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand status took 38 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand status took 81 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 32 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseState Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":457,"duration":220,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308731.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308731.wav","trackType":"wav"} Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus stop Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ------------------------------ 162ms Apr 30 17:09:51 smsl-n100 volumio[1079]: info: sendMpdCommand playlistinfo took 39 milliseconds Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: ControllerMpd::parseTrackInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ControllerMpd::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::servicePushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CorePlayQueue::getTrack 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":220,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"308731.wav","artist":null,"album":null,"uri":"http://192.168.1.35:16000/audio/308731.wav","trackType":"wav"} Apr 30 17:09:51 smsl-n100 volumio[1079]: verbose: CURRENT POSITION 13 Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState stateService play Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::syncState currentStatus play Apr 30 17:09:51 smsl-n100 volumio[1079]: info: Received an update from plugin. extracting info from payload Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:51 smsl-n100 volumio[1079]: info: ------------------------------ 294ms Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreStateMachine::pushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 17:09:51 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioPushState Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output update for this device Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MRS: Pushing multiroomSync output Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: MAXVOL, message: Apr 30 17:09:51 smsl-n100 volumio[1079]: error: Serial API: Failed to decode command: 100, message: undefined Apr 30 17:09:51 smsl-n100 volumio[1079]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Apr 30 17:10:09 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 17:10:09 smsl-n100 volumio[1079]: info: Preload queue cleared Apr 30 17:10:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 17:10:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 17:10:15 smsl-n100 volumio[1079]: info: Discovery: Getting this device information Apr 30 17:10:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::volumioGetState Apr 30 17:10:15 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 17:10:20 smsl-n100 volumio[1079]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 30 17:10:20 smsl-n100 volumio[1079]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 17:10:20 smsl-n100 volumio[1079]: TypeError: Cannot read property 'length' of undefined Apr 30 17:10:20 smsl-n100 volumio[1079]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Apr 30 17:10:20 smsl-n100 volumio[1079]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Apr 30 17:10:20 smsl-n100 volumio[1079]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Apr 30 17:10:20 smsl-n100 volumio[1079]: at Parser.emit (events.js:400:28) Apr 30 17:10:20 smsl-n100 volumio[1079]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Apr 30 17:10:20 smsl-n100 volumio[1079]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Apr 30 17:10:20 smsl-n100 volumio[1079]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Apr 30 17:10:20 smsl-n100 volumio[1079]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Apr 30 17:10:20 smsl-n100 volumio[1079]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Apr 30 17:10:20 smsl-n100 volumio[1079]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Apr 30 17:10:20 smsl-n100 volumio[1079]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Apr 30 17:10:20 smsl-n100 volumio[1079]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Apr 30 17:10:20 smsl-n100 volumio[1079]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Apr 30 17:10:20 smsl-n100 volumio[1079]: at IncomingMessage.emit (events.js:412:35) Apr 30 17:10:20 smsl-n100 volumio[1079]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 30 17:10:20 smsl-n100 volumio[1079]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 30 17:10:20 smsl-n100 volumio[1079]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 17:10:21 smsl-n100 sudo[6649]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-30 17:09 Apr 30 17:10:21 smsl-n100 sudo[6649]: 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="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="723ba1d50268911818ebdca474fb7656df6050cb" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="smsl" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 14 Feb 2025 02:46:15 PM CET" VOLUMIO_VERSION="3.789" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR_MODEL="SMSL S100" VOLUMIO_VENDOR="SMSL" VOLUMIO_MODEL="S100" VOLUMIO_HASH="215d731aee688e00fb3cc923952be9a7"