-- Logs begin at Sun 2025-08-31 16:06:46 MSK, end at Sun 2025-08-31 16:09:30 MSK. -- Aug 31 16:08:00 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:00 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:01 volumio volumio[2141]: info: BOOT COMPLETED Aug 31 16:08:02 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:02 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:02 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:02 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:03 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:04 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:06 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:07 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:07 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:07 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:12 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:12 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:14 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:14 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:14 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:14 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 in service upnp_browser Aug 31 16:08:14 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add in service upnp_browser Aug 31 16:08:15 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:16 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:08:16 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:08:16 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:16 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:16 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:08:16 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:16 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:16 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:16 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:16 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:16 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:16 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:16 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:16 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:16 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 in service upnp_browser Aug 31 16:08:16 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:16 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:17 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:17 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:20 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:20 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:08:20 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:08:20 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:20 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:20 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:08:20 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:20 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:20 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:20 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:20 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:20 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 in service upnp_browser Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:20 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 in service upnp_browser Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:20 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 in service upnp_browser Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:20 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec in service upnp_browser Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:20 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 in service upnp_browser Aug 31 16:08:20 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:20 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:22 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:23 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:23 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::play index 5 Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:23 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:23 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:23 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:23 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:23 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:08:23 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:23 volumio volumio[2141]: info: [1756645703517] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:08:23 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:23 volumio volumio[2141]: info: sendMpdCommand stop took 3 milliseconds Aug 31 16:08:23 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:08:23 volumio volumio[2141]: info: Aug 31 16:08:23 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:23 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:23 volumio volumio[2141]: info: sendMpdCommand clear took 1 milliseconds Aug 31 16:08:23 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:23 volumio volumio[2141]: info: Aug 31 16:08:23 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:23 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:23 volumio volumio[2141]: info: Aug 31 16:08:23 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:23 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:23 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:23 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:24 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:24 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 562ms Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 561ms Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:24 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" took 1 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:24 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:24 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand play took 1 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 18 milliseconds Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 19 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 19 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 24ms Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: Aug 31 16:08:24 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 5 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":535,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:24 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":535,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:24 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 40ms Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 41ms Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 17 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 16 milliseconds Aug 31 16:08:24 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 17 milliseconds Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:24 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:24 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:24 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:24 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:24 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:24 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:24 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 45ms Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 43ms Aug 31 16:08:24 volumio volumio[2141]: info: ------------------------------ 42ms Aug 31 16:08:25 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::stPlaybackTimer Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::serviceStop Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::serviceStop Aug 31 16:08:25 volumio volumio[2141]: info: [1756645705019] ControllerUPNPBrowser::stop Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:25 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:25 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:25 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::play index 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: [1756645705026] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand stop took 24 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand stop took 18 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 2 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand clear took 2 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav" Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: No code Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: No code Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 24ms Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 23ms Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:25 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:25 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 26ms Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 25 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav" Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 29ms Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav" took 6 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:25 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand play took 2 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 0ms Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 2 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 4ms Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: Aug 31 16:08:25 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 2 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 0 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:25 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:25 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 18ms Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 17ms Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:08:25 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:25 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:25 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:25 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:25 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/d40fda38d9448a92dbebfa704c0ae501.wav%3Finfokey%3D4364817b2e145e539496378d59530930%3Bfileext%3D.wav","trackType":"wav"} Aug 31 16:08:25 volumio volumio[2141]: verbose: CURRENT POSITION 0 Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:25 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:25 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 45ms Aug 31 16:08:25 volumio volumio[2141]: info: ------------------------------ 44ms Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::play index 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:26 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:26 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:26 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::stPlaybackTimer Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::serviceStop Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 0 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::serviceStop Aug 31 16:08:26 volumio volumio[2141]: info: [1756645706090] ControllerUPNPBrowser::stop Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand stop took 20 milliseconds Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: [1756645706111] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:26 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand stop took 1 milliseconds Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:26 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:26 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:26 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand clear took 3 milliseconds Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand status took 2 milliseconds Aug 31 16:08:26 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/T-eb1be6e5397c0b02ca7a1ef3ce00deab.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:26 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:26 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 16:08:26 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: No code Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 31 16:08:26 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: No code Aug 31 16:08:26 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:26 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:26 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:26 volumio volumio[2141]: info: ------------------------------ 22ms Aug 31 16:08:26 volumio volumio[2141]: info: ------------------------------ 22ms Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:26 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:26 volumio volumio[2141]: info: Aug 31 16:08:26 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:26 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:27 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:27 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:28 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:28 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:28 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:28 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:28 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:28 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::play index 5 Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:28 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:28 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:28 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:28 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:28 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:08:28 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:28 volumio volumio[2141]: info: [1756645708090] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:08:28 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 4310ms Aug 31 16:08:30 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4308 milliseconds Aug 31 16:08:30 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-eb1be6e5397c0b02ca7a1ef3ce00deab.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:30 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:30 volumio volumio[2141]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 4314ms Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 4291ms Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 4290ms Aug 31 16:08:30 volumio volumio[2141]: info: sendMpdCommand stop took 2336 milliseconds Aug 31 16:08:30 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-eb1be6e5397c0b02ca7a1ef3ce00deab.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" took 2 milliseconds Aug 31 16:08:30 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:08:30 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:08:30 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 4ms Aug 31 16:08:30 volumio volumio[2141]: info: sendMpdCommand clear took 3 milliseconds Aug 31 16:08:30 volumio volumio[2141]: info: sendMpdCommand play took 3 milliseconds Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:30 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: info: Aug 31 16:08:30 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:30 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:30 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:30 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:32 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:32 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-34af6bc2124ed1714d0a691fba38ffb7 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-4ccce408fbe7b7b62f7cd94434a05665 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-c7b355b210758c56620cbdc9f02329d9 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-f325084c651b589b5f51dc2bfb17eaec Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-b4242d25478c964430a8556ba172d901 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d40fda38d9448a92dbebfa704c0ae501 Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::play index 5 Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:08:32 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@cd34442781df9414196c4228e3200c5d Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@97bcd8ac0848d274c3e5553557fa6e0e Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5dec99fcbdfd30c98c290d1d2f1d01c4 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@0bd251932a92e737c89f92731deb60c6 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6705515433432e9f7174be4967ca2d21 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@9dcc015967006af23b8edf6b353b0846 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3e24e3618f04e370930317ef3cd59111 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@dadda44a48b6615e1fc7e77831b3f589 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@5ecd2b213f99884cbe6fe5fc17a0acb0 Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@2a526ea53103b6245d98f017141a8add Aug 31 16:08:32 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:32 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e1f6be01026a0c606ebe3f56be21d7b5 Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:32 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:32 volumio volumio[2141]: info: [1756645712231] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:08:32 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:08:32 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:32 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 4260ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 4260ms Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand stop took 2458 milliseconds Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand clear took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 3ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 3ms Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand play took 2 milliseconds Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 17ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 17ms Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand play took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 0ms Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:08:34 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 2ms Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 0 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 8ms Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: info: Aug 31 16:08:34 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:34 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:34 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:34 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 35ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 34ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 32ms Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 26 milliseconds Aug 31 16:08:34 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 26 milliseconds Aug 31 16:08:34 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:34 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:08:34 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:08:34 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:08:34 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:08:34 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:08:34 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 57ms Aug 31 16:08:34 volumio volumio[2141]: info: ------------------------------ 57ms Aug 31 16:08:34 volumio volumio[2141]: info: peppy_screensaver: Start PeppyMeter Aug 31 16:08:37 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:37 volumio sudo[2670]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:08:37 volumio sudo[2670]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:08:38 volumio sudo[2670]: pam_unix(sudo:session): session closed for user root Aug 31 16:08:43 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:43 volumio sudo[2689]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:08:43 volumio sudo[2689]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:08:43 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:43 volumio sudo[2689]: pam_unix(sudo:session): session closed for user root Aug 31 16:08:44 volumio volumio[2141]: info: peppy_screensaver: Start PeppyMeter Aug 31 16:08:48 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:49 volumio sudo[2780]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:08:49 volumio sudo[2780]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:08:49 volumio sudo[2780]: pam_unix(sudo:session): session closed for user root Aug 31 16:08:54 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:08:54 volumio sudo[2819]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:08:54 volumio sudo[2819]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:08:54 volumio volumio[2141]: info: peppy_screensaver: Start PeppyMeter Aug 31 16:08:55 volumio sudo[2819]: pam_unix(sudo:session): session closed for user root Aug 31 16:08:57 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:08:57 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:09:00 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:00 volumio sudo[2849]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:09:00 volumio sudo[2849]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:09:00 volumio sudo[2849]: pam_unix(sudo:session): session closed for user root Aug 31 16:09:04 volumio volumio[2141]: info: peppy_screensaver: Start PeppyMeter Aug 31 16:09:05 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:05 volumio sudo[2896]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:09:05 volumio sudo[2896]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:09:06 volumio sudo[2896]: pam_unix(sudo:session): session closed for user root Aug 31 16:09:11 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:11 volumio sudo[2918]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:09:11 volumio sudo[2918]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:09:11 volumio sudo[2918]: pam_unix(sudo:session): session closed for user root Aug 31 16:09:12 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 31 16:09:12 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@fd64bff112c73f864526d76ff8c6d66a Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6f12cb271fced01d4afc22316739d362 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@c8e3b4a5434925e6fbf1c266dc16997e Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@babc718d0882e12c9605eeb0cd57020b Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@8910a97fb9fdc24059d3834476d586b2 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e55960d3a759c72825ecb504bb5d192a Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3d757258366e93ab6ff6aefc1cae75c2 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ca608043ac370c88e79d60f2f9f3aac8 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@085a6e53915b844ec53145a7489deaf8 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d853d937d07ea255734d820043a14235 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@10b4fe1e42860ca8d4b7006ba89a7f61 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@883da9dbd79655861feba3e52d2f2230 Aug 31 16:09:12 volumio volumio[2141]: info: Preloading song: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6b8f84613c733d6fa7c5e794ee1cf443 Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@fd64bff112c73f864526d76ff8c6d66a in service upnp_browser Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6f12cb271fced01d4afc22316739d362 in service upnp_browser Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@c8e3b4a5434925e6fbf1c266dc16997e in service upnp_browser Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@babc718d0882e12c9605eeb0cd57020b in service upnp_browser Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@8910a97fb9fdc24059d3834476d586b2 in service upnp_browser Aug 31 16:09:12 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e55960d3a759c72825ecb504bb5d192a in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3d757258366e93ab6ff6aefc1cae75c2 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ca608043ac370c88e79d60f2f9f3aac8 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@085a6e53915b844ec53145a7489deaf8 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d853d937d07ea255734d820043a14235 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@10b4fe1e42860ca8d4b7006ba89a7f61 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@883da9dbd79655861feba3e52d2f2230 in service upnp_browser Aug 31 16:09:13 volumio volumio[2141]: info: Exploding uri upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6b8f84613c733d6fa7c5e794ee1cf443 in service upnp_browser Aug 31 16:09:14 volumio volumio[2141]: info: peppy_screensaver: Start PeppyMeter Aug 31 16:09:15 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::ClearQueue Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::stPlaybackTimer Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::serviceStop Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::serviceStop Aug 31 16:09:15 volumio volumio[2141]: info: [1756645755137] ControllerUPNPBrowser::stop Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::clearPlayQueue Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:09:15 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-28f24322316a6072195a84882f8a9859 Aug 31 16:09:15 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ST-28f24322316a6072195a84882f8a9859 in service upnp_browser Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-3e973ad4beb0be03fbcd2ccd0c574cb7 Aug 31 16:09:15 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-3e973ad4beb0be03fbcd2ccd0c574cb7 in service upnp_browser Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-fe364bf5639f3dc884ac3de307625b83 Aug 31 16:09:15 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@TF-fe364bf5639f3dc884ac3de307625b83 in service upnp_browser Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-8a6e3b142069c1f3923441df6c889155 Aug 31 16:09:15 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@SF-8a6e3b142069c1f3923441df6c889155 in service upnp_browser Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-811e12205c1c5d5911f58628418102d5 Aug 31 16:09:15 volumio volumio[2141]: info: Exploding uri upnp/folder/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@UF-811e12205c1c5d5911f58628418102d5 in service upnp_browser Aug 31 16:09:15 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@fd64bff112c73f864526d76ff8c6d66a Aug 31 16:09:15 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@fd64bff112c73f864526d76ff8c6d66a Aug 31 16:09:15 volumio volumio[2141]: info: Aug 31 16:09:15 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand stop took 23 milliseconds Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand status took 0 milliseconds Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:15 volumio volumio[2141]: info: Aug 31 16:09:15 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:15 volumio volumio[2141]: info: Aug 31 16:09:15 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: 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-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:15 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: No code Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: ------------------------------ 15ms Aug 31 16:09:15 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:09:15 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: 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-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:15 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: No code Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: 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-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-be7a5265c10a5e58006cbfc131ea4d7e.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:15 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState stateService stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: No code Aug 31 16:09:15 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:15 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:15 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:15 volumio volumio[2141]: info: ------------------------------ 42ms Aug 31 16:09:15 volumio volumio[2141]: info: ------------------------------ 43ms Aug 31 16:09:16 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:16 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:21 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:21 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:09:21 volumio volumio[2141]: info: CoreCommandRouter::volumioPlay Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::play index 5 Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::addQueueItems Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::addQueueItems Aug 31 16:09:21 volumio volumio[2141]: info: Preload queue cleared Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6f12cb271fced01d4afc22316739d362 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6f12cb271fced01d4afc22316739d362 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@c8e3b4a5434925e6fbf1c266dc16997e Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@c8e3b4a5434925e6fbf1c266dc16997e Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@babc718d0882e12c9605eeb0cd57020b Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@babc718d0882e12c9605eeb0cd57020b Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@8910a97fb9fdc24059d3834476d586b2 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@8910a97fb9fdc24059d3834476d586b2 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e55960d3a759c72825ecb504bb5d192a Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@e55960d3a759c72825ecb504bb5d192a Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3d757258366e93ab6ff6aefc1cae75c2 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@3d757258366e93ab6ff6aefc1cae75c2 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ca608043ac370c88e79d60f2f9f3aac8 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@ca608043ac370c88e79d60f2f9f3aac8 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@085a6e53915b844ec53145a7489deaf8 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@085a6e53915b844ec53145a7489deaf8 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d853d937d07ea255734d820043a14235 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@d853d937d07ea255734d820043a14235 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@10b4fe1e42860ca8d4b7006ba89a7f61 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@10b4fe1e42860ca8d4b7006ba89a7f61 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@883da9dbd79655861feba3e52d2f2230 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@883da9dbd79655861feba3e52d2f2230 Aug 31 16:09:21 volumio volumio[2141]: info: Adding Item to queue: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6b8f84613c733d6fa7c5e794ee1cf443 Aug 31 16:09:21 volumio volumio[2141]: info: Using cached record of: upnp/http://192.168.1.65:45397/UPnPServices/ContentDirectory/control@6b8f84613c733d6fa7c5e794ee1cf443 Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::stop Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:09:21 volumio volumio[2141]: info: CoreCommandRouter::volumioPushQueue Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::saveQueue Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::play index undefined Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::updateTrackBlock Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::getTrackBlock Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:21 volumio volumio[2141]: info: CoreStateMachine::startPlaybackTimer Aug 31 16:09:21 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:21 volumio volumio[2141]: info: [1756645761964] ControllerUPNPBrowser::clearAddPlayTrack Aug 31 16:09:21 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 16:09:21 volumio volumio[2141]: info: sendMpdCommand stop took 5 milliseconds Aug 31 16:09:21 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 16:09:21 volumio volumio[2141]: info: Aug 31 16:09:21 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:21 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:21 volumio volumio[2141]: info: sendMpdCommand clear took 6 milliseconds Aug 31 16:09:21 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:09:21 volumio volumio[2141]: info: Aug 31 16:09:21 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:21 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:21 volumio volumio[2141]: info: Aug 31 16:09:21 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:21 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:21 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:09:21 volumio volumio[2141]: info: ------------------------------ 3ms Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" Aug 31 16:09:22 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:09:22 volumio volumio[2141]: error: updateQueue error: null Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:22 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 540ms Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 539ms Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand add "http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3" took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand play Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:22 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces system playlist update Aug 31 16:09:22 volumio volumio[2141]: info: Ignoring MPD Status Update Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand play took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 1ms Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 0ms Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 3 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus stop Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 5ms Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: Aug 31 16:09:22 volumio volumio[2141]: ---------------------------- MPD announces state update: player Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::getState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand status Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand status took 1 milliseconds Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseState Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:09:22 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:09:22 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 19ms Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 18ms Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:09:22 volumio volumio[2141]: info: sendMpdCommand playlistinfo took 13 milliseconds Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: verbose: ControllerMpd::parseTrackInfo Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:09:22 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:09:22 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: ControllerMpd::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::servicePushState Aug 31 16:09:22 volumio volumio[2141]: info: CorePlayQueue::getTrack 5 Aug 31 16:09:22 volumio volumio[2141]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":370,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","artist":null,"album":null,"uri":"http://192.168.1.65:45397/MediaServer/AudioItems/T-05d7fde3e73ff332cc27567f57de2054.mp3%3Ftranscoding%3D1%3Binfokey%3D00b9c7ac55d99d49439c4701a31c6a9e%3Bfileext%3D.mp3","trackType":"mp3"} Aug 31 16:09:22 volumio volumio[2141]: verbose: CURRENT POSITION 5 Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState stateService play Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::syncState currentStatus play Aug 31 16:09:22 volumio volumio[2141]: info: Received an update from plugin. extracting info from payload Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreStateMachine::pushState Aug 31 16:09:22 volumio volumio[2141]: info: CoreCommandRouter::volumioPushState Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 42ms Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 41ms Aug 31 16:09:22 volumio volumio[2141]: info: ------------------------------ 41ms Aug 31 16:09:25 volumio sudo[2194]: pam_unix(sudo:session): session closed for user root Aug 31 16:09:25 volumio volumio[2141]: info: Cannot mount NAS 1 at system boot, trial number 1 ,retrying in 5 seconds Aug 31 16:09:26 volumio volumio[2141]: info: CoreCommandRouter::volumioGetState Aug 31 16:09:26 volumio sudo[2996]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 31 16:09:26 volumio sudo[2996]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 16:09:27 volumio sudo[2996]: pam_unix(sudo:session): session closed for user root Aug 31 16:09:30 volumio volumio[2141]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 16:09:30 volumio volumio[2141]: TypeError: Cannot read property 'replace' of undefined Aug 31 16:09:30 volumio volumio[2141]: at ControllerNetworkfs.mountShare (/volumio/app/plugins/system_controller/networkfs/index.js:202:28) Aug 31 16:09:30 volumio volumio[2141]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/networkfs/index.js:255:20) Aug 31 16:09:30 volumio volumio[2141]: at listOnTimeout (internal/timers.js:557:17) Aug 31 16:09:30 volumio volumio[2141]: at processTimers (internal/timers.js:500:7) Aug 31 16:09:30 volumio volumio[2141]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 16:09:30 volumio sudo[3023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 16:08 Aug 31 16:09:30 volumio sudo[3023]: 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"