-- Logs begin at Thu 2025-10-16 22:30:12 MSK, end at Thu 2025-10-16 22:33:50 MSK. -- Oct 16 22:32:01 volumio ntpd[747]: receive: Unexpected origin timestamp 0xec9bc6af.c9fa7683 does not match aorg 0000000000.00000000 from server@91.201.254.110 xmt 0xec9bc6b1.5820f7d0 Oct 16 22:32:01 volumio ntpd[747]: receive: Unexpected origin timestamp 0xec9bc6af.c9f50c33 does not match aorg 0000000000.00000000 from server@45.141.102.99 xmt 0xec9bc6b1.5a3f2c59 Oct 16 22:32:01 volumio ntpd[747]: receive: Unexpected origin timestamp 0xec9bc6af.ca050ff7 does not match aorg 0000000000.00000000 from server@46.146.231.187 xmt 0xec9bc6b1.591d8a38 Oct 16 22:32:01 volumio ntpd[747]: receive: Unexpected origin timestamp 0xec9bc6af.ca099f65 does not match aorg 0000000000.00000000 from server@195.35.71.4 xmt 0xec9bc6b1.5d219ae8 Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 22:32:05 volumio volumio[897]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 16 22:32:05 volumio volumio[897]: info: Received Get System Version Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 22:32:05 volumio volumio[897]: info: Received Get System Info Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 22:32:05 volumio volumio[897]: info: Discovery: Getting this device information Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::volumioGetState Oct 16 22:32:05 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 22:32:38 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:32:38 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:32:38 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:38 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:41 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:32:42 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17994 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17984 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17993 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17985 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17991 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17988 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17983 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17992 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17987 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17986 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17990 Oct 16 22:32:42 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17989 Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17994 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17984 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17993 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17985 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17991 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17988 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17983 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17992 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17987 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17986 in service upnp_browser Oct 16 22:32:42 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17990 in service upnp_browser Oct 16 22:32:43 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17989 in service upnp_browser Oct 16 22:32:44 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:44 volumio volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::ClearQueue Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::stPlaybackTimer Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:32:44 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:32:44 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:44 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:44 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::serviceStop Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::serviceStop Oct 16 22:32:45 volumio volumio[897]: info: [1760643165025] ControllerUPNPBrowser::stop Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::clearPlayQueue Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:32:45 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17994 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17994 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPlay Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::play index 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:32:45 volumio volumio[897]: info: Preload queue cleared Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17984 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17984 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17993 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17993 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17985 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17985 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17991 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17991 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17988 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17988 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17983 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17983 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17992 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17992 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17987 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17987 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17986 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17986 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17990 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17990 Oct 16 22:32:45 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17989 Oct 16 22:32:45 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c73494c6-17989 Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::play index undefined Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::startPlaybackTimer Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: [1760643165159] ControllerUPNPBrowser::clearAddPlayTrack Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand stop took 174 milliseconds Oct 16 22:32:45 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand stop took 44 milliseconds Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:45 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:45 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand status took 64 milliseconds Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand clear took 61 milliseconds Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand status took 56 milliseconds Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand status took 53 milliseconds Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ" Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:45 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: 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} Oct 16 22:32:45 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: No code Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: 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} Oct 16 22:32:45 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: No code Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:45 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:45 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 230ms Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 230ms Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:45 volumio volumio[897]: error: updateQueue error: null Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 203ms Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand playlistinfo took 189 milliseconds Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:45 volumio volumio[897]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 283ms Oct 16 22:32:45 volumio volumio[897]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ" Oct 16 22:32:45 volumio volumio[897]: error: updateQueue error: null Oct 16 22:32:45 volumio volumio[897]: error: updateQueue error: null Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 521ms Oct 16 22:32:45 volumio volumio[897]: info: ------------------------------ 517ms Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:45 volumio volumio[897]: info: sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ" took 14 milliseconds Oct 16 22:32:45 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 16 22:32:45 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand play Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:45 volumio volumio[897]: info: Oct 16 22:32:45 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:45 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 25ms Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand play took 19 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 20ms Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 16ms Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 37 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 40 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 36 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 10 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","artist":null,"album":null,"uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 84ms Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 44 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 35 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 16 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","artist":null,"album":null,"uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","artist":null,"album":null,"uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 312ms Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 311ms Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:46 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 244 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 217 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 215 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","artist":null,"album":null,"uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Brothers In Arms (Edit)","artist":"Dire Straits","album":"Money For Nothing (2022 Remaster)","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 481ms Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 453ms Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:46 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:32:46 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:32:46 volumio volumio[897]: info: Oct 16 22:32:46 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 286ms Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 279 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 276 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 32ms Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 27 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 27ms Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand status took 24 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Brothers In Arms (Edit)","artist":"Dire Straits","album":"Money For Nothing (2022 Remaster)","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 620ms Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 80 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 77 milliseconds Oct 16 22:32:46 volumio volumio[897]: info: sendMpdCommand playlistinfo took 77 milliseconds Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1120,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2535 Kbps","isStreaming":false,"title":"Brothers In Arms (Edit)","artist":"Dire Straits","album":"Money For Nothing (2022 Remaster)","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1370,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2672 Kbps","isStreaming":false,"title":"Brothers In Arms (Edit)","artist":"Dire Straits","album":"Money For Nothing (2022 Remaster)","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:32:46 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:32:46 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1370,"duration":299,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2672 Kbps","isStreaming":false,"title":"Brothers In Arms (Edit)","artist":"Dire Straits","album":"Money For Nothing (2022 Remaster)","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzczNDk0YzYtMTc5OTQ","trackType":""} Oct 16 22:32:46 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:32:46 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:32:46 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 540ms Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 282ms Oct 16 22:32:46 volumio volumio[897]: info: ------------------------------ 278ms Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:32:47 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:32:47 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:01 volumio volumio[897]: info: VolumeController::SetAlsaVolume80 Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:01 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:01 volumio volumio[897]: info: VolumeController::SetAlsaVolume85 Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:01 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:01 volumio volumio[897]: info: VolumeController::SetAlsaVolume90 Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:01 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:01 volumio volumio[897]: info: VolumeController::SetAlsaVolume95 Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:01 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:01 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:01 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:02 volumio volumio[897]: info: VolumeController::SetAlsaVolume90 Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:02 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:02 volumio volumio[897]: info: VolumeController::SetAlsaVolume85 Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:02 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:02 volumio volumio[897]: info: VolumeController::SetAlsaVolume80 Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:02 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:02 volumio volumio[897]: info: VolumeController::SetAlsaVolume75 Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:02 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:02 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:02 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:03 volumio volumio[897]: info: VolumeController::SetAlsaVolume80 Oct 16 22:33:03 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:03 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:03 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:03 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:03 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:03 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:20 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:20 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:21 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:22 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 Oct 16 22:33:22 volumio volumio[897]: info: Preloading song: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 in service upnp_browser Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 in service upnp_browser Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 in service upnp_browser Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 in service upnp_browser Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 in service upnp_browser Oct 16 22:33:22 volumio volumio[897]: info: Exploding uri upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 in service upnp_browser Oct 16 22:33:23 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::ClearQueue Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::stPlaybackTimer Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::serviceStop Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::serviceStop Oct 16 22:33:23 volumio volumio[897]: info: [1760643203381] ControllerUPNPBrowser::stop Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::clearPlayQueue Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:33:23 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPlay Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::play index 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:33:23 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 Oct 16 22:33:23 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 Oct 16 22:33:23 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::play index undefined Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::startPlaybackTimer Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: [1760643203476] ControllerUPNPBrowser::clearAddPlayTrack Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand stop took 119 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand stop took 26 milliseconds Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 28 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand clear took 26 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 21 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 17 milliseconds Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg" Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: 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} Oct 16 22:33:23 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: No code Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: 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} Oct 16 22:33:23 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: No code Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 210ms Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 206ms Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: error: updateQueue error: null Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 246ms Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand playlistinfo took 244 milliseconds Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg" Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 61ms Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 60ms Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:23 volumio volumio[897]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 295ms Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg" took 52 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand play Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 17ms Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand play took 14 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 12ms Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 10ms Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 31 milliseconds Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:23 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:23 volumio volumio[897]: info: Oct 16 22:33:23 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 69 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 66 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand playlistinfo took 42 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 39ms Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 24 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 22ms Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"718 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:23 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:23 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 109ms Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 51 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: ------------------------------ 49ms Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand status took 42 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand playlistinfo took 32 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 16 22:33:23 volumio volumio[897]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:23 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:23 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:23 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:23 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:23 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"743 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:23 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:24 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:24 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"717 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:24 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:24 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:24 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"760 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:24 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:24 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: ------------------------------ 341ms Oct 16 22:33:24 volumio volumio[897]: info: ------------------------------ 343ms Oct 16 22:33:24 volumio volumio[897]: info: ------------------------------ 301ms Oct 16 22:33:24 volumio volumio[897]: info: sendMpdCommand playlistinfo took 237 milliseconds Oct 16 22:33:24 volumio volumio[897]: info: sendMpdCommand playlistinfo took 236 milliseconds Oct 16 22:33:24 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:24 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:24 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"760 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:24 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:24 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:24 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":411,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"760 Kbps","isStreaming":false,"title":"Arpegiateur / Arpegiator (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzg","trackType":""} Oct 16 22:33:24 volumio volumio[897]: verbose: CURRENT POSITION 0 Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:24 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:24 volumio volumio[897]: info: ------------------------------ 461ms Oct 16 22:33:24 volumio volumio[897]: info: ------------------------------ 455ms Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:24 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:24 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:26 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::ClearQueue Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::stPlaybackTimer Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::serviceStop Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 0 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::serviceStop Oct 16 22:33:26 volumio volumio[897]: info: [1760643206037] ControllerUPNPBrowser::stop Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::clearPlayQueue Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:33:26 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17978 Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17979 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPlay Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::play index 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::addQueueItems Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::addQueueItems Oct 16 22:33:26 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17982 Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17980 Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17981 Oct 16 22:33:26 volumio volumio[897]: info: Adding Item to queue: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 Oct 16 22:33:26 volumio volumio[897]: info: Using cached record of: upnp/http://192.168.55.220:2869/upnphost/udhisapi.dll?control=uuid:21a24065-82b0-43b9-834a-55d67e844cba+urn:upnp-org:serviceId:ContentDirectory@14_ee54e8cc_1b6d5002_c370bff0_1f3cbdc8-17977 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushQueue Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::saveQueue Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::play index undefined Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::updateTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrackBlock Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::startPlaybackTimer Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: [1760643206175] ControllerUPNPBrowser::clearAddPlayTrack Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand stop took 165 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand stop took 28 milliseconds Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 45 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand clear took 44 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 41 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 39 milliseconds Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk" Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: 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} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: No code Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: 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} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: No code Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 188ms Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 187ms Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: error: updateQueue error: null Oct 16 22:33:26 volumio volumio[897]: error: updateQueue error: null Oct 16 22:33:26 volumio volumio[897]: error: updateQueue error: null Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 165ms Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 159 milliseconds Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk" Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 14ms Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 11ms Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:26 volumio volumio[897]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 217ms Oct 16 22:33:26 volumio volumio[897]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand add "http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk" took 47 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand play Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 13ms Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand play took 10 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 8ms Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 6ms Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 16 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 14 milliseconds Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 35 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 31 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 29 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 28 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 23 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 18 milliseconds Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus stop Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:26 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 113ms Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 152ms Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces system playlist update Oct 16 22:33:26 volumio volumio[897]: info: Ignoring MPD Status Update Oct 16 22:33:26 volumio volumio[897]: info: Oct 16 22:33:26 volumio volumio[897]: ---------------------------- MPD announces state update: player Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::getState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand status Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 133ms Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 127 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 118 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 116 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 114 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand playlistinfo took 113 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 25ms Oct 16 22:33:26 volumio volumio[897]: info: sendMpdCommand status took 22 milliseconds Oct 16 22:33:26 volumio volumio[897]: info: ------------------------------ 20ms Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:26 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:26 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":617,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"867 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:26 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"910 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:26 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:26 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:26 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:26 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:26 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:26 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:26 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 558ms Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 554ms Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 542ms Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 540ms Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: sendMpdCommand status took 545 milliseconds Oct 16 22:33:27 volumio volumio[897]: info: sendMpdCommand playlistinfo took 527 milliseconds Oct 16 22:33:27 volumio volumio[897]: info: sendMpdCommand playlistinfo took 521 milliseconds Oct 16 22:33:27 volumio volumio[897]: verbose: ControllerMpd::parseState Oct 16 22:33:27 volumio volumio[897]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 22:33:27 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:27 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:27 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:27 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"905 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:27 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:27 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:27 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"866 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:27 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:27 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 793ms Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 681ms Oct 16 22:33:27 volumio volumio[897]: info: sendMpdCommand playlistinfo took 129 milliseconds Oct 16 22:33:27 volumio volumio[897]: verbose: ControllerMpd::parseTrackInfo Oct 16 22:33:27 volumio volumio[897]: info: ControllerMpd::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::servicePushState Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getTrack 1 Oct 16 22:33:27 volumio volumio[897]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":467,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"866 Kbps","isStreaming":false,"title":"Equinoxe, Pt. 4 / Equinoxe Part 4 (Live - Remastered 2022)","artist":"Jean-Michel Jarre","album":"The Concerts in China (40th Anniversary - Remastered Edition (Live))","uri":"http://192.168.55.220:10243/WMPNSSv4/985694413/0_MTRfZWU1NGU4Y2NfMWI2ZDUwMDJfYzM3MGJmZjBfMWYzY2JkYzgtMTc5Nzk","trackType":""} Oct 16 22:33:27 volumio volumio[897]: verbose: CURRENT POSITION 1 Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState stateService play Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::syncState currentStatus play Oct 16 22:33:27 volumio volumio[897]: info: Received an update from plugin. extracting info from payload Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::pushState Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioPushState Oct 16 22:33:27 volumio volumio[897]: info: ------------------------------ 750ms Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreCommandRouter::volumioGetQueue Oct 16 22:33:27 volumio volumio[897]: info: CoreStateMachine::getQueue Oct 16 22:33:27 volumio volumio[897]: info: CorePlayQueue::getQueue Oct 16 22:33:33 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:33 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:36 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:36 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:38 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:38 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:47 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:47 volumio volumio[897]: info: Preload queue cleared Oct 16 22:33:49 volumio volumio[897]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 16 22:33:49 volumio volumio[897]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 22:33:49 volumio volumio[897]: TypeError: Cannot read property 'length' of undefined Oct 16 22:33:49 volumio volumio[897]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 16 22:33:49 volumio volumio[897]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 16 22:33:49 volumio volumio[897]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 16 22:33:49 volumio volumio[897]: at Parser.emit (events.js:315:20) Oct 16 22:33:49 volumio volumio[897]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 16 22:33:49 volumio volumio[897]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 16 22:33:49 volumio volumio[897]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 16 22:33:49 volumio volumio[897]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 16 22:33:49 volumio volumio[897]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 16 22:33:49 volumio volumio[897]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 16 22:33:49 volumio volumio[897]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 16 22:33:49 volumio volumio[897]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 16 22:33:49 volumio volumio[897]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 16 22:33:49 volumio volumio[897]: at IncomingMessage.emit (events.js:327:22) Oct 16 22:33:49 volumio volumio[897]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 16 22:33:49 volumio volumio[897]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 16 22:33:49 volumio volumio[897]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 22:33:50 volumio sudo[2351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-16 22:32 Oct 16 22:33:50 volumio sudo[2351]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"