-- Logs begin at Fri 2024-07-19 23:52:01 PDT, end at Sat 2024-07-20 00:00:53 PDT. -- Jul 19 23:59:02 volumio--1 volumio[939]: info: VolumeController::SetAlsaVolume14 Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 19 23:59:04 volumio--1 volumio[939]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jul 19 23:59:04 volumio--1 volumio[939]: info: VolumeController::SetAlsaVolume19 Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 19 23:59:04 volumio--1 volumio[939]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jul 19 23:59:04 volumio--1 volumio[939]: info: VolumeController::SetAlsaVolume23 Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 19 23:59:04 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 19 23:59:05 volumio--1 volumio[939]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jul 19 23:59:07 volumio--1 volumio[939]: info: VolumeController::SetAlsaVolume47 Jul 19 23:59:07 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:07 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:07 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:07 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 19 23:59:07 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 19 23:59:07 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 19 23:59:07 volumio--1 volumio[939]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jul 19 23:59:13 volumio--1 volumio[939]: info: VolumeController::SetAlsaVolume75 Jul 19 23:59:13 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:13 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:13 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:13 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 19 23:59:13 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 19 23:59:13 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 19 23:59:13 volumio--1 volumio[939]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jul 19 23:59:18 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 19 23:59:18 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:20 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 19 23:59:20 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:22 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 19 23:59:22 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:23 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 19 23:59:24 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 Jul 19 23:59:24 volumio--1 volumio[939]: info: Preloading song: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 Jul 19 23:59:24 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 in service upnp_browser Jul 19 23:59:24 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 in service upnp_browser Jul 19 23:59:24 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 in service upnp_browser Jul 19 23:59:24 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 in service upnp_browser Jul 19 23:59:25 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 in service upnp_browser Jul 19 23:59:26 volumio--1 volumio[939]: info: Exploding uri upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 in service upnp_browser Jul 19 23:59:39 volumio--1 volumiologrotate[566]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Jul 19 23:59:39 volumio--1 volumiologrotate[566]: ls: cannot access '1': No such file or directory Jul 19 23:59:40 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::ClearQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::stPlaybackTimer Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::serviceStop Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::serviceStop Jul 19 23:59:40 volumio--1 volumio[939]: info: [1721458780178] ControllerUPNPBrowser::stop Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::clearPlayQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::addQueueItems Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::addQueueItems Jul 19 23:59:40 volumio--1 volumio[939]: info: Preload queue cleared Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 Jul 19 23:59:40 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 Jul 19 23:59:40 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPlay Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::play index 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::play index undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: [1721458780236] ControllerUPNPBrowser::clearAddPlayTrack Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand stop took 70 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand stop took 16 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand clear Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 49 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand clear took 43 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 41 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 37 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: No code Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: No code Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 148ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 146ms Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: error: updateQueue error: null Jul 19 23:59:40 volumio--1 volumio[939]: error: updateQueue error: null Jul 19 23:59:40 volumio--1 volumio[939]: error: updateQueue error: null Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 131ms Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 127 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 22ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 19ms Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 188ms Jul 19 23:59:40 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 120 seconds. Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" took 29 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand play Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 19 23:59:40 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 13ms Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand play took 11 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 10ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 8ms Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 9 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 6 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 5 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: Jul 19 23:59:40 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 18 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 10 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand status took 7 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 19 23:59:40 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 19 23:59:40 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 78ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 144ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 143ms Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 118 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 115 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 115 milliseconds Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 19 23:59:40 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 19 23:59:40 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 19 23:59:40 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 19 23:59:40 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 19 23:59:40 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 19 23:59:40 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 294ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 285ms Jul 19 23:59:40 volumio--1 volumio[939]: info: ------------------------------ 283ms Jul 19 23:59:40 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 20 00:00:18 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::ClearQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::stPlaybackTimer Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::serviceStop Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::serviceStop Jul 20 00:00:18 volumio--1 volumio[939]: info: [1721458818038] ControllerUPNPBrowser::stop Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::clearPlayQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::addQueueItems Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::addQueueItems Jul 20 00:00:18 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:18 volumio--1 volumio[939]: info: Adding Item to queue: upnp/folder/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4 Jul 20 00:00:18 volumio--1 volumio[939]: info: Exploding uri upnp/folder/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4 in service upnp_browser Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand stop took 56 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 13 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 11 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 8 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 120 seconds. Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 10 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 10 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: No code Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: No code Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: No code Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 178ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 169ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 168ms Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPlay Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::play index 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::play index undefined Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: [1721458818554] ControllerUPNPBrowser::clearAddPlayTrack Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand stop took 42 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand clear Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand clear took 4 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz" Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 24ms Jul 20 00:00:18 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:18 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz" Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 68ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 65ms Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz" took 82 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand play Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 29ms Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand play took 16 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 16ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 16ms Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 11 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 8 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 7 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 17 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 12 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 13 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 12 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 10 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand status took 8 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjMz","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjMz","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:18 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjMz","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:18 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 92ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 145ms Jul 20 00:00:18 volumio--1 volumio[939]: info: ------------------------------ 144ms Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:18 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:18 volumio--1 volumio[939]: info: Jul 20 00:00:18 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 120 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 118 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 118 milliseconds Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjMz","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:18 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"\"PRINCESS MONONOKE\" Suite","artist":"Joe Hisaishi, New Japan Philharmonic World Dream Orchestra","album":"Dream Songs: The Essential Joe Hisaishi","uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:18 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:18 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:18 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:18 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"\"PRINCESS MONONOKE\" Suite","artist":"Joe Hisaishi, New Japan Philharmonic World Dream Orchestra","album":"Dream Songs: The Essential Joe Hisaishi","uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:18 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:18 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:18 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 321ms Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 311ms Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 309ms Jul 20 00:00:19 volumio--1 volumio[939]: info: Jul 20 00:00:19 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:19 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:19 volumio--1 volumio[939]: info: Jul 20 00:00:19 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:19 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:19 volumio--1 volumio[939]: info: Jul 20 00:00:19 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:19 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:19 volumio--1 volumio[939]: info: Jul 20 00:00:19 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:19 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 268ms Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand status took 265 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 89ms Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand status took 86 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 86ms Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand status took 84 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 8 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:19 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:19 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:19 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1157 Kbps","isStreaming":false,"title":"\"PRINCESS MONONOKE\" Suite","artist":"Joe Hisaishi, New Japan Philharmonic World Dream Orchestra","album":"Dream Songs: The Essential Joe Hisaishi","uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:19 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:19 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:19 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1149 Kbps","isStreaming":false,"title":"\"PRINCESS MONONOKE\" Suite","artist":"Joe Hisaishi, New Japan Philharmonic World Dream Orchestra","album":"Dream Songs: The Essential Joe Hisaishi","uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:19 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:19 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:19 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":513,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1149 Kbps","isStreaming":false,"title":"\"PRINCESS MONONOKE\" Suite","artist":"Joe Hisaishi, New Japan Philharmonic World Dream Orchestra","album":"Dream Songs: The Essential Joe Hisaishi","uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjMz","trackType":""} Jul 20 00:00:19 volumio--1 volumio[939]: verbose: CURRENT POSITION 0 Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:19 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 398ms Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 218ms Jul 20 00:00:19 volumio--1 volumio[939]: info: ------------------------------ 217ms Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::volumioGetQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreStateMachine::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: CorePlayQueue::getQueue Jul 20 00:00:19 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 20 00:00:19 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 20 00:00:20 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:26 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::ClearQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::stPlaybackTimer Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::serviceStop Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 0 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::serviceStop Jul 20 00:00:26 volumio--1 volumio[939]: info: [1721458826061] ControllerUPNPBrowser::stop Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::clearPlayQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::addQueueItems Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::addQueueItems Jul 20 00:00:26 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1633 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1666 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1706 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1705 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1679 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1693 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1692 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1697 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1694 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1699 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1606 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1589 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1607 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1590 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1608 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1591 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1592 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1609 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1593 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1610 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1594 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1611 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1612 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1595 Jul 20 00:00:26 volumio--1 volumio[939]: info: Adding Item to queue: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 Jul 20 00:00:26 volumio--1 volumio[939]: info: Using cached record of: upnp/http://192.168.1.117:2869/upnphost/udhisapi.dll?control=uuid:5a1e4952-7321-4e56-b6a0-00baa473bd6f+urn:upnp-org:serviceId:ContentDirectory@4-1613 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::saveQueue Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::updateTrackBlock Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrackBlock Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPlay Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::play index 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::play index undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::startPlaybackTimer Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: [1721458826159] ControllerUPNPBrowser::clearAddPlayTrack Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand stop Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand stop took 120 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand stop took 25 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand clear Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 35 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand clear took 34 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 34 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 33 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: No code Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: No code Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 136ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 135ms Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:26 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:26 volumio--1 volumio[939]: error: updateQueue error: null Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 121ms Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 113 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 13ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 9ms Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 161ms Jul 20 00:00:26 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 120 seconds. Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand add "http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2" took 29 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand play Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces system playlist update Jul 20 00:00:26 volumio--1 volumio[939]: info: Ignoring MPD Status Update Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 16ms Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand play took 11 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 10ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 8ms Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 15 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 11 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 7 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: Jul 20 00:00:26 volumio--1 volumio[939]: ---------------------------- MPD announces state update: player Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::getState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand status Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 16 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 13 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 12 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 13 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 9 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand status took 6 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseState Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus stop Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:26 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:26 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 77ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 120ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 117ms Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 92 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 90 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: info: sendMpdCommand playlistinfo took 89 milliseconds Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: verbose: ControllerMpd::parseTrackInfo Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:26 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:26 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ControllerMpd::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::servicePushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CorePlayQueue::getTrack 1 Jul 20 00:00:26 volumio--1 volumio[939]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":187,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_NC0xNjY2","artist":null,"album":null,"uri":"http://192.168.1.117:10243/WMPNSSv4/2054023755/0_NC0xNjY2","trackType":""} Jul 20 00:00:26 volumio--1 volumio[939]: verbose: CURRENT POSITION 1 Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState stateService play Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::syncState currentStatus play Jul 20 00:00:26 volumio--1 volumio[939]: info: Received an update from plugin. extracting info from payload Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreStateMachine::pushState Jul 20 00:00:26 volumio--1 volumio[939]: info: CoreCommandRouter::volumioPushState Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 275ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 264ms Jul 20 00:00:26 volumio--1 volumio[939]: info: ------------------------------ 263ms Jul 20 00:00:26 volumio--1 volumio[939]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 20 00:00:37 volumio--1 systemd[1]: Starting Daily man-db regeneration... Jul 20 00:00:37 volumio--1 systemd[1]: man-db.service: Succeeded. Jul 20 00:00:37 volumio--1 systemd[1]: Started Daily man-db regeneration. Jul 20 00:00:39 volumio--1 volumiologrotate[566]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Jul 20 00:00:39 volumio--1 volumiologrotate[566]: ls: cannot access '1': No such file or directory Jul 20 00:00:45 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 20 00:00:45 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:46 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 20 00:00:46 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:47 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 20 00:00:48 volumio--1 volumio[939]: info: Preload queue cleared Jul 20 00:00:52 volumio--1 volumio[939]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 20 00:00:52 volumio--1 volumio[939]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 20 00:00:52 volumio--1 volumio[939]: TypeError: Cannot read property 'length' of undefined Jul 20 00:00:52 volumio--1 volumio[939]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 20 00:00:52 volumio--1 volumio[939]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 20 00:00:52 volumio--1 volumio[939]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 20 00:00:52 volumio--1 volumio[939]: at Parser.emit (events.js:315:20) Jul 20 00:00:52 volumio--1 volumio[939]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 20 00:00:52 volumio--1 volumio[939]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 20 00:00:52 volumio--1 volumio[939]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 20 00:00:52 volumio--1 volumio[939]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 20 00:00:52 volumio--1 volumio[939]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 20 00:00:52 volumio--1 volumio[939]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 20 00:00:52 volumio--1 volumio[939]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 20 00:00:52 volumio--1 volumio[939]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 20 00:00:52 volumio--1 volumio[939]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 20 00:00:52 volumio--1 volumio[939]: at IncomingMessage.emit (events.js:327:22) Jul 20 00:00:52 volumio--1 volumio[939]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 20 00:00:52 volumio--1 volumio[939]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 20 00:00:52 volumio--1 volumio[939]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 20 00:00:53 volumio--1 sudo[2166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-19 23:59 Jul 20 00:00:53 volumio--1 sudo[2166]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"