-- Logs begin at Mon 2024-08-19 13:48:08 UTC, end at Mon 2024-08-19 14:50:14 UTC. -- Aug 19 14:49:09 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::ClearQueue Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:11 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::stPlaybackTimer Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::serviceStop Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::serviceStop Aug 19 14:49:11 volumio volumio[10030]: info: [1724078951427] ControllerUPNPBrowser::stop Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::clearPlayQueue Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::addQueueItems Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::addQueueItems Aug 19 14:49:11 volumio volumio[10030]: info: Adding Item to queue: upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a144 Aug 19 14:49:11 volumio volumio[10030]: info: Exploding uri upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a144 in service upnp_browser Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPlay Aug 19 14:49:11 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::play index 0 Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:11 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::play index undefined Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::startPlaybackTimer Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: info: [1724078951696] ControllerUPNPBrowser::clearAddPlayTrack Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand stop took 292 milliseconds Aug 19 14:49:11 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand stop took 23 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand clear Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:11 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand status took 23 milliseconds Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand clear took 18 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Ivana*20Gavric*20-*20Chopin*20-*20(24-96,*20Edition,*202017)/01.*20Mazurkas,*20Op.*206*20II.*20Sotto*20voce*20in*20C-Sharp*20Minor.flac" Aug 19 14:49:11 volumio volumio[10030]: error: updateQueue error: null Aug 19 14:49:11 volumio volumio[10030]: info: ------------------------------ 31ms Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 17 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:11 volumio volumio[10030]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 19 14:49:11 volumio volumio[10030]: info: ------------------------------ 63ms Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Ivana*20Gavric*20-*20Chopin*20-*20(24-96,*20Edition,*202017)/01.*20Mazurkas,*20Op.*206*20II.*20Sotto*20voce*20in*20C-Sharp*20Minor.flac" Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:11 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Ivana*20Gavric*20-*20Chopin*20-*20(24-96,*20Edition,*202017)/01.*20Mazurkas,*20Op.*206*20II.*20Sotto*20voce*20in*20C-Sharp*20Minor.flac" took 9 milliseconds Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand play Aug 19 14:49:11 volumio volumio[10030]: info: ------------------------------ 12ms Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand play took 7 milliseconds Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:11 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand status took 5 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:11 volumio volumio[10030]: info: Aug 19 14:49:11 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:11 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:11 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 12 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:11 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":162,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Mazurkas, Op. 6: II. Sotto voce in C-Sharp Minor","artist":"Ivana Gavric, Frédéric Chopin","album":"Chopin","uri":"http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Ivana*20Gavric*20-*20Chopin*20-*20(24-96,*20Edition,*202017)/01.*20Mazurkas,*20Op.*206*20II.*20Sotto*20voce*20in*20C-Sharp*20Minor.flac","trackType":"flac"} Aug 19 14:49:11 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus stop Aug 19 14:49:11 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:11 volumio volumio[10030]: info: ------------------------------ 80ms Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand status took 61 milliseconds Aug 19 14:49:11 volumio volumio[10030]: info: ------------------------------ 68ms Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:11 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 17 milliseconds Aug 19 14:49:11 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:11 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:11 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:11 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:11 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":282,"duration":162,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1350 Kbps","isStreaming":false,"title":"Mazurkas, Op. 6: II. Sotto voce in C-Sharp Minor","artist":"Ivana Gavric, Frédéric Chopin","album":"Chopin","uri":"http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Ivana*20Gavric*20-*20Chopin*20-*20(24-96,*20Edition,*202017)/01.*20Mazurkas,*20Op.*206*20II.*20Sotto*20voce*20in*20C-Sharp*20Minor.flac","trackType":"flac"} Aug 19 14:49:12 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus play Aug 19 14:49:12 volumio volumio[10030]: info: Received an update from plugin. extracting info from payload Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:12 volumio volumio[10030]: info: ------------------------------ 146ms Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:12 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:12 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:12 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:12 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:12 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:30 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::ClearQueue Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:32 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::stPlaybackTimer Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::serviceStop Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::serviceStop Aug 19 14:49:32 volumio volumio[10030]: info: [1724078972393] ControllerUPNPBrowser::stop Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::clearPlayQueue Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::addQueueItems Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::addQueueItems Aug 19 14:49:32 volumio volumio[10030]: info: Adding Item to queue: upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a2 Aug 19 14:49:32 volumio volumio[10030]: info: Exploding uri upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a2 in service upnp_browser Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:32 volumio volumio[10030]: info: CoreCommandRouter::volumioPlay Aug 19 14:49:32 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::play index 0 Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:32 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::play index undefined Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::startPlaybackTimer Aug 19 14:49:32 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:32 volumio volumio[10030]: info: [1724078972554] ControllerUPNPBrowser::clearAddPlayTrack Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:32 volumio volumio[10030]: info: Aug 19 14:49:32 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand stop took 183 milliseconds Aug 19 14:49:32 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand stop took 23 milliseconds Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand clear Aug 19 14:49:32 volumio volumio[10030]: info: Aug 19 14:49:32 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:32 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand status took 21 milliseconds Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand clear took 18 milliseconds Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/Billy*20Joel*20-*2052nd*20Street/01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf" Aug 19 14:49:32 volumio volumio[10030]: error: updateQueue error: null Aug 19 14:49:32 volumio volumio[10030]: info: ------------------------------ 32ms Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 28 milliseconds Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:32 volumio volumio[10030]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 19 14:49:32 volumio volumio[10030]: info: ------------------------------ 54ms Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/Billy*20Joel*20-*2052nd*20Street/01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf" Aug 19 14:49:32 volumio volumio[10030]: info: Aug 19 14:49:32 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:32 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/Billy*20Joel*20-*2052nd*20Street/01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf" took 13 milliseconds Aug 19 14:49:32 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand play Aug 19 14:49:32 volumio volumio[10030]: info: ------------------------------ 19ms Aug 19 14:49:32 volumio volumio[10030]: info: sendMpdCommand play took 8 milliseconds Aug 19 14:49:32 volumio volumio[10030]: info: Aug 19 14:49:32 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:32 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:32 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:33 volumio volumio[10030]: info: Aug 19 14:49:33 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:33 volumio volumio[10030]: info: sendMpdCommand status took 458 milliseconds Aug 19 14:49:33 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:33 volumio volumio[10030]: info: sendMpdCommand status took 15 milliseconds Aug 19 14:49:33 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 7 milliseconds Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:33 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:33 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:33 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":245,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2822 Kbps","isStreaming":false,"title":"01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf","artist":null,"album":null,"uri":"http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/Billy*20Joel*20-*2052nd*20Street/01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf","trackType":"dsf"} Aug 19 14:49:33 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus stop Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:33 volumio volumio[10030]: info: ------------------------------ 523ms Aug 19 14:49:33 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 40 milliseconds Aug 19 14:49:33 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:33 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:33 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:33 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":493,"duration":245,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2822 Kbps","isStreaming":false,"title":"01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf","artist":null,"album":null,"uri":"http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/Billy*20Joel*20-*2052nd*20Street/01*20-*20Billy*20Joel*20-*20Big*20Shot.dsf","trackType":"dsf"} Aug 19 14:49:33 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus play Aug 19 14:49:33 volumio volumio[10030]: info: Received an update from plugin. extracting info from payload Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:33 volumio volumio[10030]: info: ------------------------------ 117ms Aug 19 14:49:33 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:33 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:33 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:42 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::ClearQueue Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:44 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::stPlaybackTimer Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::serviceStop Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::serviceStop Aug 19 14:49:44 volumio volumio[10030]: info: [1724078984815] ControllerUPNPBrowser::stop Aug 19 14:49:44 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::clearPlayQueue Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:44 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:44 volumio volumio[10030]: info: CoreStateMachine::addQueueItems Aug 19 14:49:44 volumio volumio[10030]: info: CorePlayQueue::addQueueItems Aug 19 14:49:44 volumio volumio[10030]: info: Adding Item to queue: upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a7 Aug 19 14:49:44 volumio volumio[10030]: info: Exploding uri upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a7 in service upnp_browser Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::volumioPlay Aug 19 14:49:45 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::play index 0 Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:45 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::play index undefined Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::startPlaybackTimer Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:45 volumio volumio[10030]: info: [1724078985223] ControllerUPNPBrowser::clearAddPlayTrack Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand stop took 413 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand stop took 16 milliseconds Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand clear Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:45 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand status took 35 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand clear took 30 milliseconds Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Debicz*20*26*20Zdunik*20-*20Bach*20Stories*20-*20(24-96,*20Warner-Poland,*202017)/01-01-Sonata_in_G_Major_BWV_1027_I_Adagio_arr_-SMR.flac" Aug 19 14:49:45 volumio volumio[10030]: error: updateQueue error: null Aug 19 14:49:45 volumio volumio[10030]: info: ------------------------------ 33ms Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 24 milliseconds Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Debicz*20*26*20Zdunik*20-*20Bach*20Stories*20-*20(24-96,*20Warner-Poland,*202017)/01-01-Sonata_in_G_Major_BWV_1027_I_Adagio_arr_-SMR.flac" Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:45 volumio volumio[10030]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 19 14:49:45 volumio volumio[10030]: info: ------------------------------ 79ms Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:45 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Debicz*20*26*20Zdunik*20-*20Bach*20Stories*20-*20(24-96,*20Warner-Poland,*202017)/01-01-Sonata_in_G_Major_BWV_1027_I_Adagio_arr_-SMR.flac" took 20 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand play Aug 19 14:49:45 volumio volumio[10030]: info: ------------------------------ 16ms Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand play took 8 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:45 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand status took 472 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:45 volumio volumio[10030]: info: Aug 19 14:49:45 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:49:45 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand status took 19 milliseconds Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:45 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:45 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":281,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sonata in G Major, BWV 1027: I. Adagio (arr. for Cello & Piano)","artist":"Johann Sebastian Bach, Composer Marcin Zdunik, Cello, MainArtist Aleksander Debicz, Piano, MainArtist","album":"Aleksander Debicz & Marcin Zdunik : Bach Stories","uri":"http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Debicz*20*26*20Zdunik*20-*20Bach*20Stories*20-*20(24-96,*20Warner-Poland,*202017)/01-01-Sonata_in_G_Major_BWV_1027_I_Adagio_arr_-SMR.flac","trackType":"flac"} Aug 19 14:49:45 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus stop Aug 19 14:49:45 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:45 volumio volumio[10030]: info: ------------------------------ 553ms Aug 19 14:49:45 volumio volumio[10030]: info: ------------------------------ 59ms Aug 19 14:49:45 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 40 milliseconds Aug 19 14:49:45 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:49:45 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:49:45 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:49:45 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:49:45 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":490,"duration":281,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2056 Kbps","isStreaming":false,"title":"Sonata in G Major, BWV 1027: I. Adagio (arr. for Cello & Piano)","artist":"Johann Sebastian Bach, Composer Marcin Zdunik, Cello, MainArtist Aleksander Debicz, Piano, MainArtist","album":"Aleksander Debicz & Marcin Zdunik : Bach Stories","uri":"http://192.168.50.78:9790/minimserver/*/2018/*e5*8f*a4*e5*85*b8*e9*ab*98*e6*a0*bc/Debicz*20*26*20Zdunik*20-*20Bach*20Stories*20-*20(24-96,*20Warner-Poland,*202017)/01-01-Sonata_in_G_Major_BWV_1027_I_Adagio_arr_-SMR.flac","trackType":"flac"} Aug 19 14:49:46 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus play Aug 19 14:49:46 volumio volumio[10030]: info: Received an update from plugin. extracting info from payload Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:49:46 volumio volumio[10030]: info: ------------------------------ 136ms Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:46 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:46 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:49:46 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:49:46 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:49:59 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::ClearQueue Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:50:00 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::stPlaybackTimer Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::serviceStop Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::serviceStop Aug 19 14:50:00 volumio volumio[10030]: info: [1724079000595] ControllerUPNPBrowser::stop Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::clearPlayQueue Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::addQueueItems Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::addQueueItems Aug 19 14:50:00 volumio volumio[10030]: info: Adding Item to queue: upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a485 Aug 19 14:50:00 volumio volumio[10030]: info: Exploding uri upnp/folder/http://192.168.50.78:9791/65bf2aab-f5c9-49ee-ab9e-f3bbde7550aa/upnp.org-ContentDirectory-1/control@0$albums$*a485 in service upnp_browser Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::saveQueue Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioPushQueue Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::updateTrackBlock Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrackBlock Aug 19 14:50:00 volumio volumio[10030]: info: CoreCommandRouter::volumioPlay Aug 19 14:50:00 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::play index 0 Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::stop Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:50:00 volumio volumio[10030]: verbose: UNSET VOLATILE Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::play index undefined Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::startPlaybackTimer Aug 19 14:50:00 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:00 volumio volumio[10030]: info: [1724079000775] ControllerUPNPBrowser::clearAddPlayTrack Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand stop Aug 19 14:50:00 volumio volumio[10030]: info: Aug 19 14:50:00 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand stop took 201 milliseconds Aug 19 14:50:00 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand stop took 22 milliseconds Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand clear Aug 19 14:50:00 volumio volumio[10030]: info: Aug 19 14:50:00 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:50:00 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand status took 63 milliseconds Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand clear took 47 milliseconds Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/The*20Beach*20Boys*20-*20Sunflower/01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf" Aug 19 14:50:00 volumio volumio[10030]: error: updateQueue error: null Aug 19 14:50:00 volumio volumio[10030]: info: ------------------------------ 46ms Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 28 milliseconds Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:50:00 volumio volumio[10030]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 19 14:50:00 volumio volumio[10030]: info: ------------------------------ 110ms Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/The*20Beach*20Boys*20-*20Sunflower/01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf" Aug 19 14:50:00 volumio volumio[10030]: info: Aug 19 14:50:00 volumio volumio[10030]: ---------------------------- MPD announces system playlist update Aug 19 14:50:00 volumio volumio[10030]: info: Ignoring MPD Status Update Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand add "http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/The*20Beach*20Boys*20-*20Sunflower/01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf" took 3 milliseconds Aug 19 14:50:00 volumio volumio[10030]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand play Aug 19 14:50:00 volumio volumio[10030]: info: ------------------------------ 10ms Aug 19 14:50:00 volumio volumio[10030]: info: sendMpdCommand play took 5 milliseconds Aug 19 14:50:00 volumio volumio[10030]: info: Aug 19 14:50:00 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:50:00 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:50:00 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:50:01 volumio volumio[10030]: info: Aug 19 14:50:01 volumio volumio[10030]: ---------------------------- MPD announces state update: player Aug 19 14:50:01 volumio volumio[10030]: info: sendMpdCommand status took 460 milliseconds Aug 19 14:50:01 volumio volumio[10030]: info: ControllerMpd::getState Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand status Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:50:01 volumio volumio[10030]: info: sendMpdCommand status took 19 milliseconds Aug 19 14:50:01 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 19 milliseconds Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::parseState Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:50:01 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:50:01 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:01 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":142,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2822 Kbps","isStreaming":false,"title":"01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf","artist":null,"album":null,"uri":"http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/The*20Beach*20Boys*20-*20Sunflower/01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf","trackType":"dsf"} Aug 19 14:50:01 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus stop Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:50:01 volumio volumio[10030]: info: ------------------------------ 527ms Aug 19 14:50:01 volumio volumio[10030]: info: sendMpdCommand playlistinfo took 47 milliseconds Aug 19 14:50:01 volumio volumio[10030]: verbose: ControllerMpd::parseTrackInfo Aug 19 14:50:01 volumio volumio[10030]: info: ControllerMpd::pushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::servicePushState Aug 19 14:50:01 volumio volumio[10030]: info: CorePlayQueue::getTrack 0 Aug 19 14:50:01 volumio volumio[10030]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":142,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2822 Kbps","isStreaming":false,"title":"01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf","artist":null,"album":null,"uri":"http://192.168.50.78:9790/minimserver/*/2018/DSD*e9*9d*9e*e5*8f*a4*e5*85*b8/The*20Beach*20Boys*20-*20Sunflower/01*20-*20The*20Beach*20Boys*20-*20Slip*20on*20Through.dsf","trackType":"dsf"} Aug 19 14:50:01 volumio volumio[10030]: verbose: CURRENT POSITION 0 Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::syncState stateService play Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::syncState currentStatus play Aug 19 14:50:01 volumio volumio[10030]: info: Received an update from plugin. extracting info from payload Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::pushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::volumioPushState Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 19 14:50:01 volumio volumio[10030]: info: ------------------------------ 106ms Aug 19 14:50:01 volumio volumio[10030]: info: CoreCommandRouter::volumioGetQueue Aug 19 14:50:01 volumio volumio[10030]: info: CoreStateMachine::getQueue Aug 19 14:50:01 volumio volumio[10030]: info: CorePlayQueue::getQueue Aug 19 14:50:06 volumio volumio[10030]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Billy%20Joel/52nd%20Street/3ed23350-fa85-418c-bf70-3890f866eb2f.jpg' Aug 19 14:50:13 volumio volumio[10030]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 19 14:50:13 volumio volumio[10030]: { Error: connect ETIMEDOUT 128.121.243.228:443 Aug 19 14:50:13 volumio volumio[10030]: at Object._errnoException (util.js:1022:11) Aug 19 14:50:13 volumio volumio[10030]: at _exceptionWithHostPort (util.js:1044:20) Aug 19 14:50:13 volumio volumio[10030]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Aug 19 14:50:13 volumio volumio[10030]: code: 'ETIMEDOUT', Aug 19 14:50:13 volumio volumio[10030]: errno: 'ETIMEDOUT', Aug 19 14:50:13 volumio volumio[10030]: syscall: 'connect', Aug 19 14:50:13 volumio volumio[10030]: address: '128.121.243.228', Aug 19 14:50:13 volumio volumio[10030]: port: 443 } Aug 19 14:50:13 volumio volumio[10030]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 19 14:50:14 volumio sudo[11297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-19 14:49 Aug 19 14:50:14 volumio sudo[11297]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 8 (jessie)" NAME="Debian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=debian HOME_URL="http://www.debian.org/" SUPPORT_URL="http://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="958dedc0edff114f244fa9acc70cf53089d9e5ae" VOLUMIO_BE_VERSION="307f91893fca011201acba9973e1c41bd3a0ad5d" VOLUMIO_ARCH="x86" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Oct 1 11:49:13 CEST 2021" VOLUMIO_VERSION="2.916" VOLUMIO_HARDWARE="x86" VOLUMIO_HASH="62511ec23417b6085328d5bda7373a0c"