-- Logs begin at Mon 2025-09-15 14:52:41 +05, end at Mon 2025-09-15 15:07:14 +05. -- Sep 15 15:06:00 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:06:00 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 15 15:06:03 volumio volumio[998]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 15 15:06:03 volumio volumio[998]: info: Received Get System Version Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 15:06:03 volumio volumio[998]: info: Received Get System Info Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 15:06:03 volumio volumio[998]: info: Discovery: Getting this device information Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::volumioGetState Sep 15 15:06:03 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 15:06:03 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:06:04 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ac11fc1d92ffe8a02d393f76ae74081e Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4113efdd3bd6f39b47a24f631a840852 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@aa023f640a1ffb298ac5848e7189cc15 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2efa8faf7d0cf494139cd57ef7947d10 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@a563aa436ddcf9970201b456f52a59d2 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@d4f7d327e6405451666d78215c03fefe Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fb92b1a5129d1937127657e144fd989c Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@3ba9f8da109c114ed347eab73878ff52 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@27ea870525cf09714389900e7b57a165 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00aa52fdd85983c19f9c8d5a5a7aa48d Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2325033a0b7e829743376e3d81dd9303 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c7119078dd3782ef835599920ec871f9 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4f15adc5da6691c09a8c09f77ad01925 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@bc6cf79215610d08f5c8a5f5abd7acf0 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@445affea5eff98dde6dfd92eeed887b9 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@0db62553d7ea402456230c333252b052 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@16f5f1fafc9b4a61e3e1720de98da567 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fec378c6fdf62d8fc29df19a211e1e23 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@cadcff3bf55a4074170e857cee30dc37 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ef718ab45336e7a0a4607f0ad4745771 Sep 15 15:06:04 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6d9f7873468b49bf20653782f1c5259a Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ac11fc1d92ffe8a02d393f76ae74081e in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4113efdd3bd6f39b47a24f631a840852 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@aa023f640a1ffb298ac5848e7189cc15 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2efa8faf7d0cf494139cd57ef7947d10 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@a563aa436ddcf9970201b456f52a59d2 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@d4f7d327e6405451666d78215c03fefe in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fb92b1a5129d1937127657e144fd989c in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@3ba9f8da109c114ed347eab73878ff52 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@27ea870525cf09714389900e7b57a165 in service upnp_browser Sep 15 15:06:04 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00aa52fdd85983c19f9c8d5a5a7aa48d in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2325033a0b7e829743376e3d81dd9303 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c7119078dd3782ef835599920ec871f9 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4f15adc5da6691c09a8c09f77ad01925 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@bc6cf79215610d08f5c8a5f5abd7acf0 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@445affea5eff98dde6dfd92eeed887b9 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@0db62553d7ea402456230c333252b052 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@16f5f1fafc9b4a61e3e1720de98da567 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fec378c6fdf62d8fc29df19a211e1e23 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@cadcff3bf55a4074170e857cee30dc37 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ef718ab45336e7a0a4607f0ad4745771 in service upnp_browser Sep 15 15:06:05 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6d9f7873468b49bf20653782f1c5259a in service upnp_browser Sep 15 15:06:06 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:06 volumio volumio[998]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 15:06:06 volumio volumio[998]: info: CoreStateMachine::ClearQueue Sep 15 15:06:06 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:06 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::serviceStop Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::serviceStop Sep 15 15:06:07 volumio volumio[998]: info: ControllerMpd::stop Sep 15 15:06:07 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::clearPlayQueue Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:07 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6a16e22e172fdff00ebaaa4cc956a0dd Sep 15 15:06:07 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6a16e22e172fdff00ebaaa4cc956a0dd in service upnp_browser Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-bb0ede53d434e625a0e2714b5217ea30 Sep 15 15:06:07 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-bb0ede53d434e625a0e2714b5217ea30 in service upnp_browser Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-e3e05b7e81efffb3183e5464b174a752 Sep 15 15:06:07 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-e3e05b7e81efffb3183e5464b174a752 in service upnp_browser Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-afcdfb97e601360c9d8f1976597af1af Sep 15 15:06:07 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-afcdfb97e601360c9d8f1976597af1af in service upnp_browser Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-c095ac12c680270f79a4b1b9fac02a17 Sep 15 15:06:07 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-c095ac12c680270f79a4b1b9fac02a17 in service upnp_browser Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ac11fc1d92ffe8a02d393f76ae74081e Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ac11fc1d92ffe8a02d393f76ae74081e Sep 15 15:06:07 volumio volumio[998]: info: sendMpdCommand stop took 59 milliseconds Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: verbose: STATE SERVICE {"status":"stop","service":"motherearthradio","type":"webradio","trackType":"flac","radioType":"mer","albumart":"https://motherearth.streamserver24.com/api/station/motherearth_instrumental/art/40e22e5155f873b512dbe674-1686933778.jpg","uri":"https://motherearth.streamserver24.com/listen/motherearth_instrumental/motherearth.instrumental.aac","name":"Manu Delago - Plus Minus","title":"Plus Minus","artist":"Manu Delago","album":"Silver Kobalt","streaming":true,"disableUiControls":true,"duration":272,"seek":0,"bitdepth":"24 bit","channels":2} Sep 15 15:06:07 volumio volumio[998]: verbose: CURRENT POSITION 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::syncState stateService stop Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:07 volumio volumio[998]: info: No code Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 0 Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPlay Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::play index 5 Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:07 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4113efdd3bd6f39b47a24f631a840852 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4113efdd3bd6f39b47a24f631a840852 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@aa023f640a1ffb298ac5848e7189cc15 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@aa023f640a1ffb298ac5848e7189cc15 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2efa8faf7d0cf494139cd57ef7947d10 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2efa8faf7d0cf494139cd57ef7947d10 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@a563aa436ddcf9970201b456f52a59d2 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@a563aa436ddcf9970201b456f52a59d2 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@d4f7d327e6405451666d78215c03fefe Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@d4f7d327e6405451666d78215c03fefe Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fb92b1a5129d1937127657e144fd989c Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fb92b1a5129d1937127657e144fd989c Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@3ba9f8da109c114ed347eab73878ff52 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@3ba9f8da109c114ed347eab73878ff52 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@27ea870525cf09714389900e7b57a165 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@27ea870525cf09714389900e7b57a165 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00aa52fdd85983c19f9c8d5a5a7aa48d Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00aa52fdd85983c19f9c8d5a5a7aa48d Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2325033a0b7e829743376e3d81dd9303 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@2325033a0b7e829743376e3d81dd9303 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c7119078dd3782ef835599920ec871f9 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c7119078dd3782ef835599920ec871f9 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4f15adc5da6691c09a8c09f77ad01925 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@4f15adc5da6691c09a8c09f77ad01925 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@bc6cf79215610d08f5c8a5f5abd7acf0 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@bc6cf79215610d08f5c8a5f5abd7acf0 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@445affea5eff98dde6dfd92eeed887b9 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@445affea5eff98dde6dfd92eeed887b9 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@0db62553d7ea402456230c333252b052 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@0db62553d7ea402456230c333252b052 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@16f5f1fafc9b4a61e3e1720de98da567 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@16f5f1fafc9b4a61e3e1720de98da567 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fec378c6fdf62d8fc29df19a211e1e23 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@fec378c6fdf62d8fc29df19a211e1e23 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@cadcff3bf55a4074170e857cee30dc37 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@cadcff3bf55a4074170e857cee30dc37 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ef718ab45336e7a0a4607f0ad4745771 Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ef718ab45336e7a0a4607f0ad4745771 Sep 15 15:06:07 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6d9f7873468b49bf20653782f1c5259a Sep 15 15:06:07 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6d9f7873468b49bf20653782f1c5259a Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:07 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::play index undefined Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:07 volumio volumio[998]: info: CoreStateMachine::startPlaybackTimer Sep 15 15:06:07 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:07 volumio volumio[998]: info: [1757930767641] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 15:06:07 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 15:06:07 volumio volumio[998]: info: sendMpdCommand stop took 15 milliseconds Sep 15 15:06:07 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand clear Sep 15 15:06:07 volumio volumio[998]: info: Sep 15 15:06:07 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:07 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:07 volumio volumio[998]: info: sendMpdCommand clear took 5 milliseconds Sep 15 15:06:07 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" Sep 15 15:06:07 volumio volumio[998]: info: Sep 15 15:06:07 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:07 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:07 volumio volumio[998]: info: Sep 15 15:06:07 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:07 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:07 volumio volumio[998]: error: Upnp client error: Error: This socket has been ended by the other party Sep 15 15:06:08 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 536ms Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" Sep 15 15:06:08 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:08 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:08 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 537ms Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 534ms Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand add "http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" took 5 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand play Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:08 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:08 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 13ms Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand play took 9 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 8ms Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 6ms Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 17 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 16 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 13 milliseconds Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: info: Sep 15 15:06:08 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 26 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 25 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 19 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 18 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 12 milliseconds Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:08 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:08 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 139ms Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 240ms Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 234ms Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand status took 207 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 198 milliseconds Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 191 milliseconds Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":295,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:08 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":455,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:08 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 418ms Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 403ms Sep 15 15:06:08 volumio volumio[998]: info: sendMpdCommand playlistinfo took 219 milliseconds Sep 15 15:06:08 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:08 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:08 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:08 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":637,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:08 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:08 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:08 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:08 volumio volumio[998]: info: ------------------------------ 528ms Sep 15 15:06:26 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 15:06:26 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 15:06:26 volumio volumio[998]: info: Discovery: Getting this device information Sep 15 15:06:26 volumio volumio[998]: info: CoreCommandRouter::volumioGetState Sep 15 15:06:26 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::volumioPause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::servicePause Sep 15 15:06:27 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::servicePause Sep 15 15:06:27 volumio volumio[998]: info: [1757930787480] ControllerUPNPBrowser::pause Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand pause Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand pause took 2 milliseconds Sep 15 15:06:27 volumio volumio[998]: info: Sep 15 15:06:27 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:27 volumio volumio[998]: info: Sep 15 15:06:27 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:27 volumio volumio[998]: info: Sep 15 15:06:27 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand status took 6 milliseconds Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand status took 4 milliseconds Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand status took 7 milliseconds Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:27 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:27 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":20102,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:27 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:27 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:27 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":20102,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:27 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:27 volumio volumio[998]: info: ------------------------------ 66ms Sep 15 15:06:27 volumio volumio[998]: info: ------------------------------ 64ms Sep 15 15:06:27 volumio volumio[998]: info: sendMpdCommand playlistinfo took 51 milliseconds Sep 15 15:06:27 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:27 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:27 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:27 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":20102,"duration":147,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:27 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:27 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:27 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:27 volumio volumio[998]: info: ------------------------------ 89ms Sep 15 15:06:37 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:06:37 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:37 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 Sep 15 15:06:37 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 Sep 15 15:06:37 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 in service upnp_browser Sep 15 15:06:37 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::ClearQueue Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::serviceStop Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::serviceStop Sep 15 15:06:40 volumio volumio[998]: info: [1757930800711] ControllerUPNPBrowser::stop Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::clearPlayQueue Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:40 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6eef440ca636b9844ad1d947303e6466 Sep 15 15:06:40 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6eef440ca636b9844ad1d947303e6466 in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-3daff2c5d50d3e8b8075447a5d7f07fc Sep 15 15:06:40 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-3daff2c5d50d3e8b8075447a5d7f07fc in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-c6bcce0b04e660db6ce175d64f0d1927 Sep 15 15:06:40 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-c6bcce0b04e660db6ce175d64f0d1927 in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-85ef406401c3fe14c614afc6b7565b5d Sep 15 15:06:40 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-85ef406401c3fe14c614afc6b7565b5d in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-59095650e55c6c110ab276460be1a1f0 Sep 15 15:06:40 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-59095650e55c6c110ab276460be1a1f0 in service upnp_browser Sep 15 15:06:40 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 Sep 15 15:06:40 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 Sep 15 15:06:40 volumio volumio[998]: info: Sep 15 15:06:40 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand stop took 55 milliseconds Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:40 volumio volumio[998]: info: Sep 15 15:06:40 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:40 volumio volumio[998]: info: Sep 15 15:06:40 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand status took 11 milliseconds Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand status took 8 milliseconds Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand status took 5 milliseconds Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 15 15:06:40 volumio volumio[998]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:40 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:40 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState stateService stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: No code Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:40 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState stateService stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: No code Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-e771f163f2605902195339d99bc53e61.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:40 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState stateService stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:40 volumio volumio[998]: info: No code Sep 15 15:06:40 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:40 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:40 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:41 volumio volumio[998]: info: ------------------------------ 238ms Sep 15 15:06:41 volumio volumio[998]: info: ------------------------------ 236ms Sep 15 15:06:41 volumio volumio[998]: info: ------------------------------ 235ms Sep 15 15:06:41 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:41 volumio volumio[998]: info: CoreCommandRouter::volumioPlay Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::play index 5 Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:41 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:41 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 Sep 15 15:06:41 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:41 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::play index undefined Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:41 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:41 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:46 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:46 volumio volumio[998]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::ClearQueue Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::clearPlayQueue Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:46 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:46 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6eef440ca636b9844ad1d947303e6466 Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-6eef440ca636b9844ad1d947303e6466 Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-3daff2c5d50d3e8b8075447a5d7f07fc Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-3daff2c5d50d3e8b8075447a5d7f07fc Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-c6bcce0b04e660db6ce175d64f0d1927 Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-c6bcce0b04e660db6ce175d64f0d1927 Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-85ef406401c3fe14c614afc6b7565b5d Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-85ef406401c3fe14c614afc6b7565b5d Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-59095650e55c6c110ab276460be1a1f0 Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-59095650e55c6c110ab276460be1a1f0 Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@196ff7aac31d6a385ffa380de1c176b7 Sep 15 15:06:46 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:46 volumio volumio[998]: info: CoreCommandRouter::volumioPlay Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::play index 5 Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:46 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:46 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 Sep 15 15:06:46 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@00244cc8d2a6c5f6f8ed3c4c0790ed85 Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:46 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::play index undefined Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:46 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:46 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:53 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:06:53 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:54 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:06:54 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c8849ffaaa4f20b504330875b432b0d2 Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6537518d28d08fc53e067892ee41dc5f Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c81f6bf9dc87182817f50ae440bacb81 Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@79800a939a12fc41eb4c7aa0b24a5741 Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@788e531cab7a9c66ffec7ae71d5499a9 Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@988b2e3af1accd2ee7a48d38f48f4cae Sep 15 15:06:54 volumio volumio[998]: info: Preloading song: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@1e93d6f8d53fe5df71a76d7e6302a3b3 Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c8849ffaaa4f20b504330875b432b0d2 in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6537518d28d08fc53e067892ee41dc5f in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c81f6bf9dc87182817f50ae440bacb81 in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@79800a939a12fc41eb4c7aa0b24a5741 in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@788e531cab7a9c66ffec7ae71d5499a9 in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@988b2e3af1accd2ee7a48d38f48f4cae in service upnp_browser Sep 15 15:06:54 volumio volumio[998]: info: Exploding uri upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@1e93d6f8d53fe5df71a76d7e6302a3b3 in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:55 volumio volumio[998]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 15:06:55 volumio volumio[998]: info: CoreStateMachine::ClearQueue Sep 15 15:06:55 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:55 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:55 volumio volumio[998]: info: CorePlayQueue::clearPlayQueue Sep 15 15:06:55 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:55 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:55 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:55 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:55 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-ada49a2834f5889bffc9f08fc8824614 Sep 15 15:06:55 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@ST-ada49a2834f5889bffc9f08fc8824614 in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-e95e8b9d524ce8fe42a978b1368c63ab Sep 15 15:06:55 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-e95e8b9d524ce8fe42a978b1368c63ab in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-60642b9ebf2fb7dd443e5ff8883fff43 Sep 15 15:06:55 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@TF-60642b9ebf2fb7dd443e5ff8883fff43 in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-ee1b4809bf176c9a568527a425243b70 Sep 15 15:06:55 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@SF-ee1b4809bf176c9a568527a425243b70 in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-06835de7a4b399be7694168681c680d8 Sep 15 15:06:55 volumio volumio[998]: info: Exploding uri upnp/folder/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@UF-06835de7a4b399be7694168681c680d8 in service upnp_browser Sep 15 15:06:55 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c8849ffaaa4f20b504330875b432b0d2 Sep 15 15:06:55 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c8849ffaaa4f20b504330875b432b0d2 Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::volumioPlay Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::play index 5 Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::addQueueItems Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::addQueueItems Sep 15 15:06:56 volumio volumio[998]: info: Preload queue cleared Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6537518d28d08fc53e067892ee41dc5f Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@6537518d28d08fc53e067892ee41dc5f Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c81f6bf9dc87182817f50ae440bacb81 Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@c81f6bf9dc87182817f50ae440bacb81 Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@79800a939a12fc41eb4c7aa0b24a5741 Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@79800a939a12fc41eb4c7aa0b24a5741 Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@788e531cab7a9c66ffec7ae71d5499a9 Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@788e531cab7a9c66ffec7ae71d5499a9 Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@988b2e3af1accd2ee7a48d38f48f4cae Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@988b2e3af1accd2ee7a48d38f48f4cae Sep 15 15:06:56 volumio volumio[998]: info: Adding Item to queue: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@1e93d6f8d53fe5df71a76d7e6302a3b3 Sep 15 15:06:56 volumio volumio[998]: info: Using cached record of: upnp/http://192.168.0.103:45397/UPnPServices/ContentDirectory/control@1e93d6f8d53fe5df71a76d7e6302a3b3 Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::stop Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::volumioPushQueue Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::saveQueue Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::play index undefined Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::updateTrackBlock Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::getTrackBlock Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::startPlaybackTimer Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:56 volumio volumio[998]: info: [1757930816361] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 15:06:56 volumio volumio[998]: info: sendMpdCommand stop took 17 milliseconds Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand clear Sep 15 15:06:56 volumio volumio[998]: info: sendMpdCommand clear took 12 milliseconds Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 15:06:56 volumio volumio[998]: info: Discovery: Getting this device information Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::volumioGetState Sep 15 15:06:56 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:56 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 15:06:56 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:56 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:56 volumio volumio[998]: error: updateQueue error: null Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 543ms Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 539ms Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 528ms Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: sendMpdCommand add "http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav" took 4 milliseconds Sep 15 15:06:56 volumio volumio[998]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand play Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces system playlist update Sep 15 15:06:56 volumio volumio[998]: info: Ignoring MPD Status Update Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 15ms Sep 15 15:06:56 volumio volumio[998]: info: sendMpdCommand play took 16 milliseconds Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 15ms Sep 15 15:06:56 volumio volumio[998]: info: ------------------------------ 12ms Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:56 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:56 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:56 volumio volumio[998]: info: Sep 15 15:06:56 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:57 volumio volumio[998]: info: Sep 15 15:06:57 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:57 volumio volumio[998]: info: Sep 15 15:06:57 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 23 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 14 milliseconds Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: info: Sep 15 15:06:57 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:57 volumio volumio[998]: info: Sep 15 15:06:57 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 26 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 22 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 20 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 19 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 12 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand status took 9 milliseconds Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus stop Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:57 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 99ms Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 136ms Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 97 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 97 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 94 milliseconds Sep 15 15:06:57 volumio volumio[998]: info: sendMpdCommand playlistinfo took 93 milliseconds Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:57 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:57 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:57 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:57 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:06:57 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:06:57 volumio volumio[998]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:06:57 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState stateService play Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus play Sep 15 15:06:57 volumio volumio[998]: info: Received an update from plugin. extracting info from payload Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:06:57 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 447ms Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 444ms Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 435ms Sep 15 15:06:57 volumio volumio[998]: info: ------------------------------ 433ms Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::volumioPause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::servicePause Sep 15 15:07:02 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::servicePause Sep 15 15:07:02 volumio volumio[998]: info: [1757930822772] ControllerUPNPBrowser::pause Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand pause Sep 15 15:07:02 volumio volumio[998]: info: Sep 15 15:07:02 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand pause took 4 milliseconds Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:07:02 volumio volumio[998]: info: Sep 15 15:07:02 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:07:02 volumio volumio[998]: info: Sep 15 15:07:02 volumio volumio[998]: ---------------------------- MPD announces state update: player Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::getState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand status Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand status took 8 milliseconds Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand status took 5 milliseconds Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand status took 3 milliseconds Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseState Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 15 15:07:02 volumio volumio[998]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:07:02 volumio volumio[998]: verbose: ControllerMpd::parseTrackInfo Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:07:02 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:07:02 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6716,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:07:02 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:07:02 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:07:02 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6716,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:07:02 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:07:02 volumio volumio[998]: info: ControllerMpd::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::servicePushState Sep 15 15:07:02 volumio volumio[998]: info: CorePlayQueue::getTrack 5 Sep 15 15:07:02 volumio volumio[998]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6716,"duration":190,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.0.103:45397/MediaServer/AudioItems/T-490c76aca6af46fb3bbfe4558e244c06.wav%3Ftranscoding%3D1%3Bclientuuid%3D26295a1a-c404-415a-8ae8-f7dcc2045e99%3Binfokey%3D0e8ed36fddcbbb1d7964d191bec0ba1b%3Bupdateid%3D17179869184%3Bfileext%3D.wav","trackType":"wav"} Sep 15 15:07:02 volumio volumio[998]: verbose: CURRENT POSITION 5 Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState stateService pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::syncState currentStatus pause Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::pushState Sep 15 15:07:02 volumio volumio[998]: info: CoreCommandRouter::volumioPushState Sep 15 15:07:02 volumio volumio[998]: info: CoreStateMachine::stPlaybackTimer Sep 15 15:07:02 volumio volumio[998]: info: ------------------------------ 126ms Sep 15 15:07:02 volumio volumio[998]: info: ------------------------------ 129ms Sep 15 15:07:02 volumio volumio[998]: info: ------------------------------ 127ms Sep 15 15:07:14 volumio volumio[998]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 15:07:14 volumio volumio[998]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 15:07:14 volumio volumio[998]: TypeError: Cannot read property 'length' of undefined Sep 15 15:07:14 volumio volumio[998]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 15 15:07:14 volumio volumio[998]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 15 15:07:14 volumio volumio[998]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 15 15:07:14 volumio volumio[998]: at Parser.emit (events.js:400:28) Sep 15 15:07:14 volumio volumio[998]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 15 15:07:14 volumio volumio[998]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 15 15:07:14 volumio volumio[998]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 15 15:07:14 volumio volumio[998]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 15 15:07:14 volumio volumio[998]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 15 15:07:14 volumio volumio[998]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 15 15:07:14 volumio volumio[998]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 15 15:07:14 volumio volumio[998]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 15 15:07:14 volumio volumio[998]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 15 15:07:14 volumio volumio[998]: at IncomingMessage.emit (events.js:412:35) Sep 15 15:07:14 volumio volumio[998]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 15 15:07:14 volumio volumio[998]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 15 15:07:14 volumio volumio[998]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 15:07:14 volumio sudo[3957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-15 15:06 Sep 15 15:07:14 volumio sudo[3957]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"