-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2026-03-28 15:50:44 CET. -- Mar 28 15:49:00 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:00 volumio volumio[1004]: info: Listing playlists Mar 28 15:49:00 volumio volumio[1004]: info: Listing playlists Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:01 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:01 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:01 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:01 volumio volumio[1004]: info: [1774709341865] ControllerUPNPBrowser::seek Mar 28 15:49:01 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:01 volumio volumio[1004]: error: null Mar 28 15:49:01 volumio volumio[1004]: info: Mar 28 15:49:01 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:01 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:01 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:01 volumio volumio[1004]: info: sendMpdCommand status took 6 milliseconds Mar 28 15:49:01 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:01 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:01 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 9 milliseconds Mar 28 15:49:01 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:01 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:01 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:01 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:01 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:01 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:01 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:01 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:01 volumio volumio[1004]: info: ------------------------------ 60ms Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:02 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:02 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:02 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:02 volumio volumio[1004]: info: [1774709342863] ControllerUPNPBrowser::seek Mar 28 15:49:02 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:02 volumio volumio[1004]: error: null Mar 28 15:49:02 volumio volumio[1004]: info: Mar 28 15:49:02 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:02 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:02 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:02 volumio volumio[1004]: info: sendMpdCommand status took 8 milliseconds Mar 28 15:49:02 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:02 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:02 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:49:02 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:02 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:02 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:02 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":116000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:02 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:02 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:02 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:02 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:02 volumio volumio[1004]: info: ------------------------------ 73ms Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:03 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:03 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:03 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:03 volumio volumio[1004]: info: [1774709343402] ControllerUPNPBrowser::seek Mar 28 15:49:03 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:03 volumio volumio[1004]: error: null Mar 28 15:49:03 volumio volumio[1004]: info: Mar 28 15:49:03 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:03 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:03 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:03 volumio volumio[1004]: info: sendMpdCommand status took 19 milliseconds Mar 28 15:49:03 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:03 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:03 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:49:03 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:03 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:03 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:03 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":161000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:03 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:03 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:03 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:03 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:03 volumio volumio[1004]: info: ------------------------------ 75ms Mar 28 15:49:03 volumio volumio[1004]: verbose: New Socket.io Connection to 192.168.5.33:3000 from 192.168.5.12 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:49:04 volumio volumio[1004]: info: Discovery: Getting this device information Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: info: [1774709344051] ControllerUPNPBrowser::seek Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: error: null Mar 28 15:49:04 volumio volumio[1004]: info: Mar 28 15:49:04 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:04 volumio volumio[1004]: info: sendMpdCommand status took 18 milliseconds Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:04 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:04 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:04 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: info: ------------------------------ 72ms Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: info: [1774709344557] ControllerUPNPBrowser::seek Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: error: null Mar 28 15:49:04 volumio volumio[1004]: info: Mar 28 15:49:04 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:04 volumio volumio[1004]: info: sendMpdCommand status took 12 milliseconds Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:04 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 15:49:04 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:04 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:04 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:04 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":352000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:04 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:04 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:04 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:04 volumio volumio[1004]: info: ------------------------------ 47ms Mar 28 15:49:05 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:05 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:05 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:05 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:05 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:05 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:05 volumio volumio[1004]: info: [1774709345990] ControllerUPNPBrowser::seek Mar 28 15:49:05 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:05 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:05 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:05 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: error: null Mar 28 15:49:06 volumio volumio[1004]: info: Mar 28 15:49:06 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:06 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:06 volumio volumio[1004]: info: sendMpdCommand status took 3 milliseconds Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:06 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:06 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:06 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":442000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:06 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:06 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: info: ------------------------------ 58ms Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:06 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:06 volumio volumio[1004]: info: [1774709346920] ControllerUPNPBrowser::seek Mar 28 15:49:06 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: error: null Mar 28 15:49:06 volumio volumio[1004]: info: Mar 28 15:49:06 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:06 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:06 volumio volumio[1004]: info: sendMpdCommand status took 2 milliseconds Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:06 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 15:49:06 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:06 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:06 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":537000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:06 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:06 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:06 volumio volumio[1004]: info: ------------------------------ 28ms Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:08 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:08 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:08 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:08 volumio volumio[1004]: info: [1774709348260] ControllerUPNPBrowser::seek Mar 28 15:49:08 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:08 volumio volumio[1004]: error: null Mar 28 15:49:08 volumio volumio[1004]: info: Mar 28 15:49:08 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:08 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:08 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:08 volumio volumio[1004]: info: sendMpdCommand status took 3 milliseconds Mar 28 15:49:08 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:08 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:08 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 15:49:08 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:08 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:08 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:08 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":633000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:08 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:08 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:08 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:08 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:08 volumio volumio[1004]: info: ------------------------------ 40ms Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: info: [1774709349092] ControllerUPNPBrowser::seek Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: error: null Mar 28 15:49:09 volumio volumio[1004]: info: Mar 28 15:49:09 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:09 volumio volumio[1004]: info: sendMpdCommand status took 5 milliseconds Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:09 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":730000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:09 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:09 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: info: ------------------------------ 34ms Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$2261","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/10688.jpg","artist":"","album":"'83","name":"Mixage 1","title":"Mixage 1","duration":1743} Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: info: [1774709349725] ControllerUPNPBrowser::seek Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: error: null Mar 28 15:49:09 volumio volumio[1004]: info: Mar 28 15:49:09 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:09 volumio volumio[1004]: info: sendMpdCommand status took 2 milliseconds Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:09 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:49:09 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:09 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:09 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":873000,"duration":2508,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:09 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:09 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:09 volumio volumio[1004]: info: ------------------------------ 30ms Mar 28 15:49:09 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:19 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:20 volumio volumio[1004]: info: Listing playlists Mar 28 15:49:26 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:26 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:26 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:27 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:27 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:27 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:29 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:29 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:29 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:30 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:30 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:32 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:32 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:33 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:49:33 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:34 volumio volumio[1004]: verbose: New Socket.io Connection to 192.168.5.33:3000 from 192.168.5.12 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Mar 28 15:49:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:49:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:49:34 volumio volumio[1004]: info: Discovery: Getting this device information Mar 28 15:49:34 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:49:35 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::stPlaybackTimer Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::serviceStop Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::serviceStop Mar 28 15:49:35 volumio volumio[1004]: info: [1774709375239] ControllerUPNPBrowser::stop Mar 28 15:49:35 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:35 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::play index 1 Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:35 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:35 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:35 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 1 Mar 28 15:49:35 volumio volumio[1004]: info: Mar 28 15:49:35 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:35 volumio volumio[1004]: info: sendMpdCommand stop took 162 milliseconds Mar 28 15:49:35 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:35 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:35 volumio volumio[1004]: info: sendMpdCommand status took 15 milliseconds Mar 28 15:49:35 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:35 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:35 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 28 15:49:35 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:35 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: 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":"10688.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/10688.mp3","trackType":"mp3"} Mar 28 15:49:35 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::syncState stateService stop Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:35 volumio volumio[1004]: info: No code Mar 28 15:49:35 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:35 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:35 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:35 volumio volumio[1004]: info: ------------------------------ 84ms Mar 28 15:49:35 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 28 15:49:36 volumio volumio[1004]: info: peppy_screensaver: Start PeppyMeter Mar 28 15:49:40 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:40 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:40 volumio volumio[1004]: info: Listing playlists Mar 28 15:49:40 volumio volumio[1004]: info: Listing playlists Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::play index 1 Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrack 1 Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::play index 1 Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:43 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:43 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:43 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:43 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:43 volumio volumio[1004]: info: CorePlayQueue::getTrack 1 Mar 28 15:49:44 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:44 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:44 volumio volumio[1004]: info: Adding Item to queue: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:49:44 volumio volumio[1004]: info: Using cached record of: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::play index 0 Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:44 volumio volumio[1004]: info: [1774709384529] ControllerUPNPBrowser::clearAddPlayTrack Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand stop took 6 milliseconds Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand clear took 1 milliseconds Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:49:44 volumio volumio[1004]: info: Mar 28 15:49:44 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:49:44 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:49:44 volumio volumio[1004]: error: updateQueue error: null Mar 28 15:49:44 volumio volumio[1004]: info: ------------------------------ 44ms Mar 28 15:49:44 volumio volumio[1004]: info: Mar 28 15:49:44 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:49:44 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" took 3 milliseconds Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand play Mar 28 15:49:44 volumio volumio[1004]: info: ------------------------------ 5ms Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand play took 4 milliseconds Mar 28 15:49:44 volumio volumio[1004]: info: Mar 28 15:49:44 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:44 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:44 volumio volumio[1004]: info: Mar 28 15:49:44 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand status took 7 milliseconds Mar 28 15:49:44 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand status took 2 milliseconds Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 28 15:49:44 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:44 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:44 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:44 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:44 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:49:44 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:44 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:44 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:44 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:44 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:44 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:44 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:44 volumio volumio[1004]: info: ------------------------------ 24ms Mar 28 15:49:44 volumio volumio[1004]: info: ------------------------------ 25ms Mar 28 15:49:44 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 15:49:48 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::stPlaybackTimer Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::serviceStop Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::serviceStop Mar 28 15:49:48 volumio volumio[1004]: info: [1774709388557] ControllerUPNPBrowser::stop Mar 28 15:49:48 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:48 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::play index 5 Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:48 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:49:48 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:48 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 5 Mar 28 15:49:48 volumio volumio[1004]: info: Mar 28 15:49:48 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:48 volumio volumio[1004]: info: sendMpdCommand stop took 60 milliseconds Mar 28 15:49:48 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:48 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:48 volumio volumio[1004]: info: sendMpdCommand status took 5 milliseconds Mar 28 15:49:48 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:48 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:48 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 47 milliseconds Mar 28 15:49:48 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:48 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: 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":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:48 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::syncState stateService stop Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:48 volumio volumio[1004]: info: No code Mar 28 15:49:48 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:48 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:48 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:48 volumio volumio[1004]: info: ------------------------------ 83ms Mar 28 15:49:48 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 28 15:49:49 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:49:49 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:53 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:49:53 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:49:53 volumio volumio[1004]: info: Adding Item to queue: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:49:53 volumio volumio[1004]: info: Using cached record of: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::play index 0 Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:53 volumio volumio[1004]: info: [1774709393237] ControllerUPNPBrowser::clearAddPlayTrack Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand stop took 8 milliseconds Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 15:49:53 volumio volumio[1004]: info: Mar 28 15:49:53 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:49:53 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand clear took 3 milliseconds Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:49:53 volumio volumio[1004]: error: updateQueue error: null Mar 28 15:49:53 volumio volumio[1004]: info: ------------------------------ 3ms Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:49:53 volumio volumio[1004]: info: Mar 28 15:49:53 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:49:53 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" took 1 milliseconds Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand play Mar 28 15:49:53 volumio volumio[1004]: info: ------------------------------ 3ms Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand play took 3 milliseconds Mar 28 15:49:53 volumio volumio[1004]: info: Mar 28 15:49:53 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:53 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:53 volumio volumio[1004]: info: Mar 28 15:49:53 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand status took 11 milliseconds Mar 28 15:49:53 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand status took 4 milliseconds Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:53 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:53 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:53 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:49:53 volumio volumio[1004]: info: ------------------------------ 20ms Mar 28 15:49:53 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:49:53 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:53 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:53 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:53 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:53 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:53 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:53 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:53 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:53 volumio volumio[1004]: info: ------------------------------ 31ms Mar 28 15:49:53 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:49:58 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:58 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/9262.jpg","artist":"","album":"VINIL MIX","name":"ANNI 90 COMMERCIALE","title":"ANNI 90 COMMERCIALE","duration":4624} Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:49:58 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:58 volumio volumio[1004]: info: [1774709398599] ControllerUPNPBrowser::seek Mar 28 15:49:58 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:58 volumio volumio[1004]: error: null Mar 28 15:49:58 volumio volumio[1004]: info: Mar 28 15:49:58 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:49:58 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:49:58 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:49:58 volumio volumio[1004]: info: sendMpdCommand status took 17 milliseconds Mar 28 15:49:58 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:49:58 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:49:58 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:49:58 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:49:58 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:49:58 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:49:58 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":560000,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:49:58 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:49:58 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:58 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:49:58 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:49:58 volumio volumio[1004]: info: ------------------------------ 44ms Mar 28 15:50:00 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:00 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:00 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:04 volumio volumio[1004]: verbose: New Socket.io Connection to 192.168.5.33:3000 from 192.168.5.12 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Mar 28 15:50:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:50:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:50:04 volumio volumio[1004]: info: Discovery: Getting this device information Mar 28 15:50:04 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:04 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:50:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:06 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/9262.jpg","artist":"","album":"VINIL MIX","name":"ANNI 90 COMMERCIALE","title":"ANNI 90 COMMERCIALE","duration":4624} Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:50:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:06 volumio volumio[1004]: info: [1774709406161] ControllerUPNPBrowser::seek Mar 28 15:50:06 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:06 volumio volumio[1004]: error: null Mar 28 15:50:06 volumio volumio[1004]: info: Mar 28 15:50:06 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:06 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:06 volumio volumio[1004]: info: sendMpdCommand status took 2 milliseconds Mar 28 15:50:06 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:06 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:06 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:50:06 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:06 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:06 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:06 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":953000,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:06 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:50:06 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:06 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:06 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:06 volumio volumio[1004]: info: ------------------------------ 28ms Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:50:07 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:07 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/9262.jpg","artist":"","album":"VINIL MIX","name":"ANNI 90 COMMERCIALE","title":"ANNI 90 COMMERCIALE","duration":4624} Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:50:07 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:07 volumio volumio[1004]: info: [1774709407864] ControllerUPNPBrowser::seek Mar 28 15:50:07 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:07 volumio volumio[1004]: error: null Mar 28 15:50:07 volumio volumio[1004]: info: Mar 28 15:50:07 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:07 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:07 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:07 volumio volumio[1004]: info: sendMpdCommand status took 1 milliseconds Mar 28 15:50:07 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:07 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:07 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:50:07 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:07 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:07 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:07 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1402000,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:07 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:50:07 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:07 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:07 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:07 volumio volumio[1004]: info: ------------------------------ 24ms Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::volumioSeek Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::seek Mar 28 15:50:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:09 volumio volumio[1004]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","realUri":"upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752","type":"song","albumart":"http://192.168.5.207:50002/transcoder/jpegtnscaler.cgi/folderart/9262.jpg","artist":"","album":"VINIL MIX","name":"ANNI 90 COMMERCIALE","title":"ANNI 90 COMMERCIALE","duration":4624} Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:50:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:09 volumio volumio[1004]: info: [1774709409631] ControllerUPNPBrowser::seek Mar 28 15:50:09 volumio volumio[1004]: info: ControllerMpd::seek Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:09 volumio volumio[1004]: error: null Mar 28 15:50:09 volumio volumio[1004]: info: Mar 28 15:50:09 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:09 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:09 volumio volumio[1004]: info: sendMpdCommand status took 3 milliseconds Mar 28 15:50:09 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:09 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:09 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:50:09 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:09 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:09 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:09 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4496000,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:09 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:50:09 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:09 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:09 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:09 volumio volumio[1004]: info: ------------------------------ 34ms Mar 28 15:50:10 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:16 volumio volumio[1004]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 9 Mar 28 15:50:16 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:20 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:20 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:20 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:24 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::stPlaybackTimer Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::serviceStop Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::serviceStop Mar 28 15:50:24 volumio volumio[1004]: info: [1774709424300] ControllerUPNPBrowser::stop Mar 28 15:50:24 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:50:24 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9262 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9263 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::play index 1 Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:50:24 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9264 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9265 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9266 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9267 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9268 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9269 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9270 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9271 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9272 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9273 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9274 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9275 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9276 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9277 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9278 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9279 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9280 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9282 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9283 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9284 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9285 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9286 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9287 Mar 28 15:50:24 volumio volumio[1004]: info: Adding Item to queue: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:50:24 volumio volumio[1004]: info: Using cached record of: upnp/http://192.168.5.207:50001/ContentDirectory/control@22$@9281 Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 1 Mar 28 15:50:24 volumio volumio[1004]: info: Mar 28 15:50:24 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:24 volumio volumio[1004]: info: sendMpdCommand stop took 90 milliseconds Mar 28 15:50:24 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:24 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:24 volumio volumio[1004]: info: sendMpdCommand status took 65 milliseconds Mar 28 15:50:24 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:24 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:24 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 28 15:50:24 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:24 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: 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":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:24 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::syncState stateService stop Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:24 volumio volumio[1004]: info: No code Mar 28 15:50:24 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:24 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:24 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:24 volumio volumio[1004]: info: ------------------------------ 114ms Mar 28 15:50:24 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 28 15:50:25 volumio volumio[1004]: info: peppy_screensaver: Start PeppyMeter Mar 28 15:50:29 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:29 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:32 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::ClearQueue Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::clearPlayQueue Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::addQueueItems Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::addQueueItems Mar 28 15:50:32 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:32 volumio volumio[1004]: info: Adding Item to queue: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:50:32 volumio volumio[1004]: info: Using cached record of: upnp/folder/http://192.168.5.207:50001/ContentDirectory/control@22$1752 Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioPushQueue Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::saveQueue Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::updateTrackBlock Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::getTrackBlock Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioPlay Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::play index 0 Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::stop Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::play index undefined Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::startPlaybackTimer Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:32 volumio volumio[1004]: info: [1774709432241] ControllerUPNPBrowser::clearAddPlayTrack Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand stop took 7 milliseconds Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 15:50:32 volumio volumio[1004]: info: Mar 28 15:50:32 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:50:32 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand clear took 2 milliseconds Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:50:32 volumio volumio[1004]: error: updateQueue error: null Mar 28 15:50:32 volumio volumio[1004]: info: ------------------------------ 48ms Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" Mar 28 15:50:32 volumio volumio[1004]: info: Mar 28 15:50:32 volumio volumio[1004]: ---------------------------- MPD announces system playlist update Mar 28 15:50:32 volumio volumio[1004]: info: Ignoring MPD Status Update Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand add "http://192.168.5.207:50002/m/MP3/9262.mp3" took 7 milliseconds Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand play Mar 28 15:50:32 volumio volumio[1004]: info: ------------------------------ 4ms Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand play took 3 milliseconds Mar 28 15:50:32 volumio volumio[1004]: info: Mar 28 15:50:32 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:32 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:32 volumio volumio[1004]: info: Mar 28 15:50:32 volumio volumio[1004]: ---------------------------- MPD announces state update: player Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand status took 12 milliseconds Mar 28 15:50:32 volumio volumio[1004]: info: ControllerMpd::getState Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand status Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand status took 1 milliseconds Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::parseState Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:32 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:32 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:32 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus stop Mar 28 15:50:32 volumio volumio[1004]: info: ------------------------------ 18ms Mar 28 15:50:32 volumio volumio[1004]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 15:50:32 volumio volumio[1004]: verbose: ControllerMpd::parseTrackInfo Mar 28 15:50:32 volumio volumio[1004]: info: ControllerMpd::pushState Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::servicePushState Mar 28 15:50:32 volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Mar 28 15:50:32 volumio volumio[1004]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":4625,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9262.mp3","artist":null,"album":null,"uri":"http://192.168.5.207:50002/m/MP3/9262.mp3","trackType":"mp3"} Mar 28 15:50:32 volumio volumio[1004]: verbose: CURRENT POSITION 0 Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::syncState stateService play Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::syncState currentStatus play Mar 28 15:50:32 volumio volumio[1004]: info: Received an update from plugin. extracting info from payload Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:32 volumio volumio[1004]: info: CoreStateMachine::pushState Mar 28 15:50:32 volumio volumio[1004]: info: CoreCommandRouter::volumioPushState Mar 28 15:50:32 volumio volumio[1004]: info: ------------------------------ 25ms Mar 28 15:50:32 volumio volumio[1004]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 15:50:34 volumio volumio[1004]: verbose: New Socket.io Connection to 192.168.5.33:3000 from 192.168.5.12 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Mar 28 15:50:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:50:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:50:34 volumio volumio[1004]: info: Discovery: Getting this device information Mar 28 15:50:34 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:34 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:50:38 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:50:38 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:39 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:50:39 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:39 volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Mar 28 15:50:40 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:40 volumio volumio[1004]: info: Listing playlists Mar 28 15:50:40 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:50:40 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:42 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:50:42 volumio volumio[1004]: info: Preload queue cleared Mar 28 15:50:43 volumio volumio[1004]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 28 15:50:43 volumio volumio[1004]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 15:50:43 volumio volumio[1004]: TypeError: Cannot read property 'length' of undefined Mar 28 15:50:43 volumio volumio[1004]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Mar 28 15:50:43 volumio volumio[1004]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Mar 28 15:50:43 volumio volumio[1004]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Mar 28 15:50:43 volumio volumio[1004]: at Parser.emit (events.js:315:20) Mar 28 15:50:43 volumio volumio[1004]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Mar 28 15:50:43 volumio volumio[1004]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Mar 28 15:50:43 volumio volumio[1004]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Mar 28 15:50:43 volumio volumio[1004]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Mar 28 15:50:43 volumio volumio[1004]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Mar 28 15:50:43 volumio volumio[1004]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Mar 28 15:50:43 volumio volumio[1004]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Mar 28 15:50:43 volumio volumio[1004]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Mar 28 15:50:43 volumio volumio[1004]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Mar 28 15:50:43 volumio volumio[1004]: at IncomingMessage.emit (events.js:327:22) Mar 28 15:50:43 volumio volumio[1004]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 28 15:50:43 volumio volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 28 15:50:43 volumio volumio[1004]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 15:50:44 volumio sudo[24645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-28 15:49 Mar 28 15:50:44 volumio sudo[24645]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"