-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2024-11-29 23:05:20 CET. -- Nov 29 23:04:31 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::ClearQueue Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::stPlaybackTimer Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 5 Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::serviceStop Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 5 Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::serviceStop Nov 29 23:04:31 volumio volumio[913]: info: [1732917871327] ControllerUPNPBrowser::stop Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::clearPlayQueue Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::addQueueItems Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::addQueueItems Nov 29 23:04:31 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@1c05544adbf4ef1bf6a0 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@1c05544adbf4ef1bf6a0 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d0ec30a863f941207c17 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d0ec30a863f941207c17 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c0be05c27300bf5c0b23 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c0be05c27300bf5c0b23 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@e85ab5ff9f55c4e235e2 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@e85ab5ff9f55c4e235e2 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@6ef673427563dd15a3d3 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@6ef673427563dd15a3d3 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d5e237fdb33b2f31e501 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d5e237fdb33b2f31e501 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@e7e203cd490b2b6e1d10 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@e7e203cd490b2b6e1d10 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@2203546960d3b076c6b2 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@2203546960d3b076c6b2 Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPlay Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::play index 7 Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::addQueueItems Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::addQueueItems Nov 29 23:04:31 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ce04741ee3d0ea05efe8 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ce04741ee3d0ea05efe8 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@80b724d10ccea1cbd490 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@80b724d10ccea1cbd490 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c730be1b54b132bd2f79 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c730be1b54b132bd2f79 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@4c98885191c055d571f8 Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@4c98885191c055d571f8 Nov 29 23:04:31 volumio volumio[913]: info: Adding Item to queue: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c55103a665b0e6dfe6ec Nov 29 23:04:31 volumio volumio[913]: info: Using cached record of: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@c55103a665b0e6dfe6ec Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::play index undefined Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::startPlaybackTimer Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:31 volumio volumio[913]: info: [1732917871357] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand stop took 49 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand stop took 20 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:04:31 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand status took 2 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand clear took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac" Nov 29 23:04:31 volumio volumio[913]: error: updateQueue error: null Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 2ms Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:31 volumio volumio[913]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 5ms Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac" Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:04:31 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand add "http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac" took 0 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand play Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 1ms Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand play took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand status took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand status took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:31 volumio volumio[913]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac","trackType":"flac"} Nov 29 23:04:31 volumio volumio[913]: verbose: CURRENT POSITION 7 Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState stateService play Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus stop Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 5ms Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:31 volumio volumio[913]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file.flac","artist":null,"album":null,"uri":"http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac","trackType":"flac"} Nov 29 23:04:31 volumio volumio[913]: verbose: CURRENT POSITION 7 Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState stateService play Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus play Nov 29 23:04:31 volumio volumio[913]: info: Received an update from plugin. extracting info from payload Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 32ms Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:04:31 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:04:31 volumio volumio[913]: info: Nov 29 23:04:31 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:31 volumio volumio[913]: info: ------------------------------ 9ms Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand status took 9 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:31 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:31 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:31 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:04:31 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:31 volumio volumio[913]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"819 Kbps","isStreaming":false,"title":"Podróż Do Oazy","artist":"Zbigniew Wodecki","album":"Sny Podróżnika","uri":"http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac","trackType":"flac"} Nov 29 23:04:31 volumio volumio[913]: verbose: CURRENT POSITION 7 Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState stateService play Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus play Nov 29 23:04:31 volumio volumio[913]: info: Received an update from plugin. extracting info from payload Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:31 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:31 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:31 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:32 volumio volumio[913]: info: ------------------------------ 38ms Nov 29 23:04:32 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:04:32 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:04:32 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:04:32 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:04:32 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:04:32 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:04:34 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:34 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:34 volumio kernel: hwmon hwmon1: Undervoltage detected! Nov 29 23:04:35 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:35 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:36 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:36 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:37 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:37 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:39 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:39 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:40 volumio kernel: hwmon hwmon1: Voltage normalised Nov 29 23:04:53 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:54 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:55 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:55 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:56 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:04:57 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@3bfafcf331b925432638 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d90d7885fb14fb9d55b0 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@7713f105bae49f542550 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@8c02a2f3bb7cd2f10268 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@5f753af334c78e46ef61 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@af948ddce9e0c1da4123 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@031491cbf56af6ae689d Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d1fae3164cb1f98e6d54 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@7bb15d47b3a88ce1d6b7 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@f26b2c866856a26b6f3b Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@f835d508339665699a07 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@23c18dfe4e35aa9a8abf Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@4d95519785218a2c39a1 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@392cd8d49447dc6df290 Nov 29 23:04:57 volumio volumio[913]: info: Preloading song: upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@cb0f091dfd2a54965dbe Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@3bfafcf331b925432638 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d90d7885fb14fb9d55b0 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@7713f105bae49f542550 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@8c02a2f3bb7cd2f10268 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@5f753af334c78e46ef61 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@af948ddce9e0c1da4123 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@031491cbf56af6ae689d in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@d1fae3164cb1f98e6d54 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@7bb15d47b3a88ce1d6b7 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@f26b2c866856a26b6f3b in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@f835d508339665699a07 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@23c18dfe4e35aa9a8abf in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@4d95519785218a2c39a1 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@392cd8d49447dc6df290 in service upnp_browser Nov 29 23:04:57 volumio volumio[913]: info: Exploding uri upnp/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@cb0f091dfd2a54965dbe in service upnp_browser Nov 29 23:04:58 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::ClearQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::stPlaybackTimer Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::serviceStop Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::serviceStop Nov 29 23:04:58 volumio volumio[913]: info: [1732917898539] ControllerUPNPBrowser::stop Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::clearPlayQueue Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::addQueueItems Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::addQueueItems Nov 29 23:04:58 volumio volumio[913]: info: Preload queue cleared Nov 29 23:04:58 volumio volumio[913]: info: Adding Item to queue: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 Nov 29 23:04:58 volumio volumio[913]: info: Exploding uri upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 in service upnp_browser Nov 29 23:04:58 volumio volumio[913]: info: Nov 29 23:04:58 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand stop took 27 milliseconds Nov 29 23:04:58 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand status took 1 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:58 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: 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":"Podróż Do Oazy","artist":"Zbigniew Wodecki","album":"Sny Podróżnika","uri":"http://192.168.100.2:32469/object/ce04741ee3d0ea05efe8/file.flac","trackType":"flac"} Nov 29 23:04:58 volumio volumio[913]: verbose: CURRENT POSITION 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::syncState stateService stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: No code Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 7 Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: ------------------------------ 29ms Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPlay Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::play index 0 Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::play index undefined Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::startPlaybackTimer Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:04:58 volumio volumio[913]: info: [1732917898621] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand stop took 3 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 23:04:58 volumio volumio[913]: info: Nov 29 23:04:58 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:04:58 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand clear took 1 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:04:58 volumio volumio[913]: error: updateQueue error: null Nov 29 23:04:58 volumio volumio[913]: info: ------------------------------ 2ms Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:04:58 volumio volumio[913]: info: Nov 29 23:04:58 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:04:58 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" took 0 milliseconds Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand play Nov 29 23:04:58 volumio volumio[913]: info: ------------------------------ 1ms Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand play took 0 milliseconds Nov 29 23:04:58 volumio volumio[913]: info: Nov 29 23:04:58 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:04:58 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand status took 4 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand clearerror took 2 milliseconds Nov 29 23:04:58 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:04:58 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:04:58 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:04:58 volumio volumio[913]: 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":"file.flac","artist":null,"album":null,"uri":"http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac","trackType":"flac"} Nov 29 23:04:58 volumio volumio[913]: verbose: CURRENT POSITION 0 Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::syncState stateService stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus stop Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: No code Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:04:58 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:04:58 volumio volumio[913]: info: ------------------------------ 31ms Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:04:58 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:04:58 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:01 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::ClearQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::clearPlayQueue Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::addQueueItems Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::addQueueItems Nov 29 23:05:01 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:01 volumio volumio[913]: info: Adding Item to queue: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 Nov 29 23:05:01 volumio volumio[913]: info: Using cached record of: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPlay Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::play index 0 Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::play index undefined Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::startPlaybackTimer Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:01 volumio volumio[913]: info: [1732917901907] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand stop took 2 milliseconds Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 23:05:01 volumio volumio[913]: info: Nov 29 23:05:01 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:05:01 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand clear took 1 milliseconds Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:05:01 volumio volumio[913]: error: updateQueue error: null Nov 29 23:05:01 volumio volumio[913]: info: ------------------------------ 2ms Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:05:01 volumio volumio[913]: info: Nov 29 23:05:01 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:05:01 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" took 1 milliseconds Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand play Nov 29 23:05:01 volumio volumio[913]: info: ------------------------------ 2ms Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand play took 1 milliseconds Nov 29 23:05:01 volumio volumio[913]: info: Nov 29 23:05:01 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:05:01 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand status took 3 milliseconds Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand clearerror took 1 milliseconds Nov 29 23:05:01 volumio volumio[913]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 29 23:05:01 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:05:01 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:01 volumio volumio[913]: 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":"file.flac","artist":null,"album":null,"uri":"http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac","trackType":"flac"} Nov 29 23:05:01 volumio volumio[913]: verbose: CURRENT POSITION 0 Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::syncState stateService stop Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus stop Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:01 volumio volumio[913]: info: No code Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:01 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:01 volumio volumio[913]: info: ------------------------------ 28ms Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:01 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:01 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:04 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:05:04 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:07 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::ClearQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::clearPlayQueue Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::addQueueItems Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::addQueueItems Nov 29 23:05:07 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:07 volumio volumio[913]: info: Adding Item to queue: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 Nov 29 23:05:07 volumio volumio[913]: info: Using cached record of: upnp/folder/http://192.168.100.2:32469/ContentDirectory/d346d7d8-7ca7-b3a4-5fd5-795941b9d8d9/control.xml@ac7bbd38525aacadd9e9 Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPushQueue Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::saveQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::updateTrackBlock Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getTrackBlock Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPlay Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::play index 0 Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::stop Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::play index undefined Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::startPlaybackTimer Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:07 volumio volumio[913]: info: [1732917907525] ControllerUPNPBrowser::clearAddPlayTrack Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand stop Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand stop took 2 milliseconds Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clear Nov 29 23:05:07 volumio volumio[913]: info: Nov 29 23:05:07 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:05:07 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand clear took 1 milliseconds Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:05:07 volumio volumio[913]: error: updateQueue error: null Nov 29 23:05:07 volumio volumio[913]: info: ------------------------------ 1ms Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" Nov 29 23:05:07 volumio volumio[913]: info: Nov 29 23:05:07 volumio volumio[913]: ---------------------------- MPD announces system playlist update Nov 29 23:05:07 volumio volumio[913]: info: Ignoring MPD Status Update Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand add "http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac" took 1 milliseconds Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand play Nov 29 23:05:07 volumio volumio[913]: info: ------------------------------ 1ms Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand play took 1 milliseconds Nov 29 23:05:07 volumio volumio[913]: info: Nov 29 23:05:07 volumio volumio[913]: ---------------------------- MPD announces state update: player Nov 29 23:05:07 volumio volumio[913]: info: ControllerMpd::getState Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand status Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand status took 4 milliseconds Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::parseState Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand clearerror took 0 milliseconds Nov 29 23:05:07 volumio volumio[913]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 29 23:05:07 volumio volumio[913]: verbose: ControllerMpd::parseTrackInfo Nov 29 23:05:07 volumio volumio[913]: info: ControllerMpd::pushState Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::servicePushState Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getTrack 0 Nov 29 23:05:07 volumio volumio[913]: 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":"file.flac","artist":null,"album":null,"uri":"http://192.168.100.2:32469/object/3bfafcf331b925432638/file.flac","trackType":"flac"} Nov 29 23:05:07 volumio volumio[913]: verbose: CURRENT POSITION 0 Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::syncState stateService stop Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::syncState currentStatus stop Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:07 volumio volumio[913]: info: No code Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::pushState Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioPushState Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output update for this device Nov 29 23:05:07 volumio volumio[913]: info: MRS: Pushing multiroomSync output Nov 29 23:05:07 volumio volumio[913]: info: ------------------------------ 25ms Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreCommandRouter::volumioGetQueue Nov 29 23:05:07 volumio volumio[913]: info: CoreStateMachine::getQueue Nov 29 23:05:07 volumio volumio[913]: info: CorePlayQueue::getQueue Nov 29 23:05:12 volumio volumio[913]: info: Tunnel connection is inactive, restarting it Nov 29 23:05:12 volumio volumio[913]: info: Starting Tunnel 1 Nov 29 23:05:12 volumio volumio[913]: info: Starting Tunnel Connection Checker Nov 29 23:05:12 volumio sudo[17624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Nov 29 23:05:12 volumio sudo[17624]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 23:05:12 volumio autossh[17170]: received signal to exit (15) Nov 29 23:05:12 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Nov 29 23:05:12 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Nov 29 23:05:12 volumio systemd[1]: sshtunnel.service: Succeeded. Nov 29 23:05:12 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Nov 29 23:05:12 volumio volumio[913]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 29 23:05:12 volumio volumio[913]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 29 23:05:12 volumio systemd[1]: Started MyVolumio SSH Tunnel. Nov 29 23:05:12 volumio sudo[17624]: pam_unix(sudo:session): session closed for user root Nov 29 23:05:12 volumio volumio[913]: info: Remote SSH Started Nov 29 23:05:12 volumio autossh[17629]: port set to 0, monitoring disabled Nov 29 23:05:12 volumio autossh[17629]: starting ssh (count 1) Nov 29 23:05:12 volumio autossh[17629]: ssh child pid is 17632 Nov 29 23:05:12 volumio volumio[913]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 29 23:05:12 volumio volumio[913]: info: CoreCommandRouter::volumioGetState Nov 29 23:05:15 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:05:16 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:17 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:05:17 volumio volumio[913]: info: Preload queue cleared Nov 29 23:05:19 volumio volumio[913]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 29 23:05:19 volumio volumio[913]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 23:05:19 volumio volumio[913]: TypeError: Cannot read property 'length' of undefined Nov 29 23:05:19 volumio volumio[913]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 29 23:05:19 volumio volumio[913]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 29 23:05:19 volumio volumio[913]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 29 23:05:19 volumio volumio[913]: at Parser.emit (events.js:315:20) Nov 29 23:05:19 volumio volumio[913]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 29 23:05:19 volumio volumio[913]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 29 23:05:19 volumio volumio[913]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 29 23:05:19 volumio volumio[913]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 29 23:05:19 volumio volumio[913]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 29 23:05:19 volumio volumio[913]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 29 23:05:19 volumio volumio[913]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 29 23:05:19 volumio volumio[913]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 29 23:05:19 volumio volumio[913]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 29 23:05:19 volumio volumio[913]: at IncomingMessage.emit (events.js:327:22) Nov 29 23:05:19 volumio volumio[913]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 29 23:05:19 volumio volumio[913]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 29 23:05:19 volumio volumio[913]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 23:05:20 volumio sudo[17660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-29 23:04 Nov 29 23:05:20 volumio sudo[17660]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"