-- Logs begin at Thu 2019-02-14 04:11:58 CST, end at Sun 2025-12-07 19:26:10 CST. -- Dec 07 19:25:00 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:00 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:00 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:00 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:00 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand next took 33 milliseconds Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:00 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 19 Dec 07 19:25:00 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:00 volumio volumio[1286]: verbose: CURRENT POSITION 19 Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: info: [1765157100720] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 26ms Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand stop took 19 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:00 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand clear took 13 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5952.wav" Dec 07 19:25:00 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5952.wav" Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:00 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5952.wav" took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:00 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:00 volumio volumio[1286]: info: Dec 07 19:25:00 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5952.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5952.wav","trackType":"wav"} Dec 07 19:25:00 volumio volumio[1286]: verbose: CURRENT POSITION 20 Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:00 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:00 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:00 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:00 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:00 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5952.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5952.wav","trackType":"wav"} Dec 07 19:25:00 volumio volumio[1286]: verbose: CURRENT POSITION 20 Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:00 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:00 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:00 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:00 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:00 volumio volumio[1286]: info: ------------------------------ 29ms Dec 07 19:25:00 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:01 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:01 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:01 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:03 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:03 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:03 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:03 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:04 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand next took 36 milliseconds Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:04 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 20 Dec 07 19:25:04 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:04 volumio volumio[1286]: verbose: CURRENT POSITION 20 Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: info: [1765157104042] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 29ms Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand stop took 13 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:04 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand clear took 13 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5953.flac" Dec 07 19:25:04 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5953.flac" Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:04 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5953.flac" took 1 milliseconds Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand status took 2 milliseconds Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":291,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5953.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5953.flac","trackType":"flac"} Dec 07 19:25:04 volumio volumio[1286]: verbose: CURRENT POSITION 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 6ms Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":291,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5953.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5953.flac","trackType":"flac"} Dec 07 19:25:04 volumio volumio[1286]: verbose: CURRENT POSITION 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:04 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 32ms Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:04 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:04 volumio volumio[1286]: info: Dec 07 19:25:04 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 9ms Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand status took 9 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:04 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 07 19:25:04 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:04 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:04 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":291,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"702 Kbps","isStreaming":false,"title":"天地情缘 (Chờ Trên Tháng Năm)","artist":"温兆伦","album":"NHẠC HOA LỜI VIỆT ĐÌNH ĐÁM 1 THỜI VOl.3","uri":"http://192.168.1.1:8200/MediaItems/5953.flac","trackType":"flac"} Dec 07 19:25:04 volumio volumio[1286]: verbose: CURRENT POSITION 21 Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:04 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:04 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:04 volumio volumio[1286]: info: ------------------------------ 33ms Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:04 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:04 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:04 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:04 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:04 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:04 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:04 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:04 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:05 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:05 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:05 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:06 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:06 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand next took 22 milliseconds Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:06 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 21 Dec 07 19:25:06 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:06 volumio volumio[1286]: verbose: CURRENT POSITION 21 Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: info: [1765157106734] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 31ms Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand stop took 19 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:06 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand clear took 14 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5957.flac" Dec 07 19:25:06 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5957.flac" Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:06 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5957.flac" took 0 milliseconds Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand status took 3 milliseconds Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":150,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5957.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5957.flac","trackType":"flac"} Dec 07 19:25:06 volumio volumio[1286]: verbose: CURRENT POSITION 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 7ms Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":150,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5957.flac","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5957.flac","trackType":"flac"} Dec 07 19:25:06 volumio volumio[1286]: verbose: CURRENT POSITION 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:06 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 33ms Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:06 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:06 volumio volumio[1286]: info: Dec 07 19:25:06 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 9ms Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand status took 8 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:06 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:06 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:06 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:06 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1131,"duration":150,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1673 Kbps","isStreaming":false,"title":"旧欢如梦 (Mộng Đẹp Ngày Xưa)","artist":"李克勤","album":"NHẠC HOA LỜI VIỆT ĐÌNH ĐÁM 1 THỜI VOl.3","uri":"http://192.168.1.1:8200/MediaItems/5957.flac","trackType":"flac"} Dec 07 19:25:06 volumio volumio[1286]: verbose: CURRENT POSITION 22 Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:06 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:06 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:06 volumio volumio[1286]: info: ------------------------------ 36ms Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:06 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:06 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:06 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:08 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand next took 19 milliseconds Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:08 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 22 Dec 07 19:25:08 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:08 volumio volumio[1286]: verbose: CURRENT POSITION 22 Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: info: [1765157108079] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 26ms Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand stop took 13 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::getQueue Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getQueue Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:08 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand clear took 17 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5960.wav" Dec 07 19:25:08 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 12ms Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5960.wav" Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:08 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5960.wav" took 0 milliseconds Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:08 volumio volumio[1286]: info: Dec 07 19:25:08 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5960.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5960.wav","trackType":"wav"} Dec 07 19:25:08 volumio volumio[1286]: verbose: CURRENT POSITION 23 Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 5ms Dec 07 19:25:08 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:08 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:08 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:08 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:08 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5960.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5960.wav","trackType":"wav"} Dec 07 19:25:08 volumio volumio[1286]: verbose: CURRENT POSITION 23 Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:08 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:08 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:08 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:08 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:08 volumio volumio[1286]: info: ------------------------------ 26ms Dec 07 19:25:08 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:08 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:08 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:08 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:09 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:09 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:09 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:09 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:10 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand next took 37 milliseconds Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:10 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 23 Dec 07 19:25:10 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:10 volumio volumio[1286]: verbose: CURRENT POSITION 23 Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: info: [1765157110304] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 31ms Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand stop took 16 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:10 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand clear took 12 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5961.wav" Dec 07 19:25:10 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5961.wav" Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:10 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5961.wav" took 1 milliseconds Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:10 volumio volumio[1286]: info: Dec 07 19:25:10 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":172,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5961.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5961.wav","trackType":"wav"} Dec 07 19:25:10 volumio volumio[1286]: verbose: CURRENT POSITION 24 Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:10 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 07 19:25:10 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:10 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:10 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:10 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":172,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5961.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5961.wav","trackType":"wav"} Dec 07 19:25:10 volumio volumio[1286]: verbose: CURRENT POSITION 24 Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:10 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:10 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:10 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:10 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:10 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:10 volumio volumio[1286]: info: ------------------------------ 28ms Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:12 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand next took 35 milliseconds Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:12 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 24 Dec 07 19:25:12 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:12 volumio volumio[1286]: verbose: CURRENT POSITION 24 Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: info: [1765157112392] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 28ms Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand stop took 12 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:12 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand clear took 9 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5962.wav" Dec 07 19:25:12 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5962.wav" Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:12 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5962.wav" took 0 milliseconds Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:12 volumio volumio[1286]: info: Dec 07 19:25:12 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand status took 0 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":280,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5962.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5962.wav","trackType":"wav"} Dec 07 19:25:12 volumio volumio[1286]: verbose: CURRENT POSITION 25 Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:12 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:12 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:12 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:12 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:12 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":280,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5962.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5962.wav","trackType":"wav"} Dec 07 19:25:12 volumio volumio[1286]: verbose: CURRENT POSITION 25 Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:12 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:12 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:12 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:12 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:12 volumio volumio[1286]: info: ------------------------------ 28ms Dec 07 19:25:15 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:15 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:15 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:25:15 volumio wpa_supplicant[950]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 19:25:15 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:16 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:16 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:16 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:16 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:17 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::volumioNext Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::next Dec 07 19:25:17 volumio volumio[1286]: info: ControllerMpd::next Dec 07 19:25:17 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand next Dec 07 19:25:17 volumio volumio[1286]: info: Dec 07 19:25:17 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:17 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:17 volumio volumio[1286]: info: Dec 07 19:25:17 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:17 volumio volumio[1286]: info: sendMpdCommand next took 26 milliseconds Dec 07 19:25:17 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:17 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:17 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:17 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:17 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:17 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:17 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:17 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:17 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:17 volumio volumio[1286]: info: CorePlayQueue::getTrack 25 Dec 07 19:25:17 volumio volumio[1286]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 07 19:25:17 volumio volumio[1286]: verbose: CURRENT POSITION 25 Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::syncState stateService stop Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:17 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:17 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:17 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:17 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:17 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:17 volumio volumio[1286]: info: [1765157117997] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:17 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:17 volumio volumio[1286]: info: ------------------------------ 22ms Dec 07 19:25:17 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:17 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:17 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand stop took 14 milliseconds Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:18 volumio volumio[1286]: info: Dec 07 19:25:18 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:18 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand clear took 9 milliseconds Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/5963.wav" Dec 07 19:25:18 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:18 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5963.wav" Dec 07 19:25:18 volumio volumio[1286]: info: Dec 07 19:25:18 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:18 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/5963.wav" took 0 milliseconds Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:18 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:18 volumio volumio[1286]: info: Dec 07 19:25:18 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:18 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:18 volumio volumio[1286]: info: Dec 07 19:25:18 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand status took 3 milliseconds Dec 07 19:25:18 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:18 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:18 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:18 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:18 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5963.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5963.wav","trackType":"wav"} Dec 07 19:25:18 volumio volumio[1286]: verbose: CURRENT POSITION 26 Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:18 volumio volumio[1286]: info: ------------------------------ 5ms Dec 07 19:25:18 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:18 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:18 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:18 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:18 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:18 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5963.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/5963.wav","trackType":"wav"} Dec 07 19:25:18 volumio volumio[1286]: verbose: CURRENT POSITION 26 Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:18 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:18 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:18 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:18 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:18 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:18 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:18 volumio volumio[1286]: info: ------------------------------ 24ms Dec 07 19:25:22 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 07 19:25:22 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:22 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 in service upnp_browser Dec 07 19:25:22 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 in service upnp_browser Dec 07 19:25:23 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 in service upnp_browser Dec 07 19:25:23 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:23 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:23 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:23 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:23 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:23 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:24 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:24 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:24 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::ClearQueue Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::stPlaybackTimer Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::serviceStop Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 26 Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::serviceStop Dec 07 19:25:24 volumio volumio[1286]: info: [1765157124513] ControllerUPNPBrowser::stop Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::clearPlayQueue Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:24 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A Dec 07 19:25:24 volumio volumio[1286]: info: Exploding uri upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A in service upnp_browser Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPlay Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::play index 1 Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:24 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:24 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:24 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:24 volumio volumio[1286]: info: [1765157124551] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:24 volumio volumio[1286]: info: Dec 07 19:25:24 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand stop took 40 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand stop took 3 milliseconds Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:24 volumio volumio[1286]: info: Dec 07 19:25:24 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:24 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand clear took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/6059.dsd" Dec 07 19:25:24 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:24 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:24 volumio volumio[1286]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 07 19:25:24 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6059.dsd" Dec 07 19:25:24 volumio volumio[1286]: info: Dec 07 19:25:24 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:24 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6059.dsd" took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:24 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: Dec 07 19:25:24 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:24 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:24 volumio volumio[1286]: info: Dec 07 19:25:24 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand status took 2 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:24 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:24 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6059.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6059.dsd","trackType":"dsd"} Dec 07 19:25:24 volumio volumio[1286]: verbose: CURRENT POSITION 1 Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:24 volumio volumio[1286]: info: ------------------------------ 5ms Dec 07 19:25:24 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:24 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:24 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:24 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:24 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6059.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6059.dsd","trackType":"dsd"} Dec 07 19:25:24 volumio volumio[1286]: verbose: CURRENT POSITION 1 Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:24 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:24 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:24 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:24 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:24 volumio volumio[1286]: info: ------------------------------ 29ms Dec 07 19:25:24 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:27 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:27 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:27 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:27 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:27 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:27 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:28 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:28 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:29 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:30 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::ClearQueue Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::stPlaybackTimer Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::serviceStop Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 1 Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::serviceStop Dec 07 19:25:30 volumio volumio[1286]: info: [1765157130904] ControllerUPNPBrowser::stop Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::clearPlayQueue Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:30 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPlay Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::play index 2 Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:30 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:30 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:30 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:30 volumio volumio[1286]: info: [1765157130924] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:30 volumio volumio[1286]: info: Dec 07 19:25:30 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand stop took 40 milliseconds Dec 07 19:25:30 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand stop took 21 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:30 volumio volumio[1286]: info: Dec 07 19:25:30 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:30 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand clear took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/6060.dsd" Dec 07 19:25:30 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:30 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:30 volumio volumio[1286]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 07 19:25:30 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6060.dsd" Dec 07 19:25:30 volumio volumio[1286]: info: Dec 07 19:25:30 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:30 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6060.dsd" took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:30 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: info: Dec 07 19:25:30 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:30 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:30 volumio volumio[1286]: info: Dec 07 19:25:30 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:30 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:30 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:30 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6060.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6060.dsd","trackType":"dsd"} Dec 07 19:25:30 volumio volumio[1286]: verbose: CURRENT POSITION 2 Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:30 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:30 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:30 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:30 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:30 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:30 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6060.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6060.dsd","trackType":"dsd"} Dec 07 19:25:30 volumio volumio[1286]: verbose: CURRENT POSITION 2 Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:30 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:30 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:30 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:30 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:31 volumio volumio[1286]: info: ------------------------------ 27ms Dec 07 19:25:31 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:31 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:31 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:32 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:32 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:32 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:32 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:32 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:33 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:38 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:38 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:38 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:25:38 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:39 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:39 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::ClearQueue Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::stPlaybackTimer Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::serviceStop Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::serviceStop Dec 07 19:25:39 volumio volumio[1286]: info: [1765157139276] ControllerUPNPBrowser::stop Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::clearPlayQueue Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:39 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/folder/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$A Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$0 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$1 Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPlay Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::play index 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:39 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$2 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$3 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$4 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$5 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$6 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$7 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$8 Dec 07 19:25:39 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:39 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$33$9 Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: info: [1765157139299] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:39 volumio volumio[1286]: info: Dec 07 19:25:39 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand stop took 28 milliseconds Dec 07 19:25:39 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand stop took 6 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:39 volumio volumio[1286]: info: Dec 07 19:25:39 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:39 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand status took 2 milliseconds Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand clear took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/6060.dsd" Dec 07 19:25:39 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:39 volumio volumio[1286]: info: ------------------------------ 2ms Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:39 volumio volumio[1286]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 07 19:25:39 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6060.dsd" Dec 07 19:25:39 volumio volumio[1286]: info: Dec 07 19:25:39 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:39 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6060.dsd" took 0 milliseconds Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:39 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand play took 0 milliseconds Dec 07 19:25:39 volumio volumio[1286]: info: Dec 07 19:25:39 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:39 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:39 volumio volumio[1286]: info: Dec 07 19:25:39 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:39 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:39 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6060.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6060.dsd","trackType":"dsd"} Dec 07 19:25:39 volumio volumio[1286]: verbose: CURRENT POSITION 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:39 volumio volumio[1286]: info: ------------------------------ 5ms Dec 07 19:25:39 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:39 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:39 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:39 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:39 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":276,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6060.dsd","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6060.dsd","trackType":"dsd"} Dec 07 19:25:39 volumio volumio[1286]: verbose: CURRENT POSITION 2 Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:39 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:39 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:39 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:39 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:39 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:39 volumio volumio[1286]: info: ------------------------------ 28ms Dec 07 19:25:39 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:39 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:40 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:41 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:41 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:41 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:25:42 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:42 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:42 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:42 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:42 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:43 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 07 19:25:43 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$0 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$1 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$2 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$3 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$4 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$5 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$6 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$7 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$8 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$9 Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$A Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$B Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$C Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$D Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$E Dec 07 19:25:43 volumio volumio[1286]: info: Preloading song: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$F Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$0 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$1 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$2 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$3 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$4 in service upnp_browser Dec 07 19:25:43 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$5 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$6 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$7 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$8 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$9 in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$A in service upnp_browser Dec 07 19:25:43 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$B in service upnp_browser Dec 07 19:25:44 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$C in service upnp_browser Dec 07 19:25:44 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$D in service upnp_browser Dec 07 19:25:44 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$E in service upnp_browser Dec 07 19:25:44 volumio volumio[1286]: info: Exploding uri upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$F in service upnp_browser Dec 07 19:25:45 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::ClearQueue Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::stPlaybackTimer Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::serviceStop Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 2 Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::serviceStop Dec 07 19:25:45 volumio volumio[1286]: info: [1765157145328] ControllerUPNPBrowser::stop Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::clearPlayQueue Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:45 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$0 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$0 Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPlay Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::play index 0 Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::addQueueItems Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::addQueueItems Dec 07 19:25:45 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$1 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$1 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$2 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$2 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$3 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$3 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$4 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$4 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$5 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$5 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$6 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$6 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$7 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$7 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$8 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$8 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$9 Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$9 Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$A Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$A Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$B Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$B Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$C Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$C Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$D Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$D Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$E Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$E Dec 07 19:25:45 volumio volumio[1286]: info: Adding Item to queue: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$F Dec 07 19:25:45 volumio volumio[1286]: info: Using cached record of: upnp/http://192.168.1.1:8200/ctl/ContentDir@64$2$0$1$34$F Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::stop Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::saveQueue Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::play index undefined Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::startPlaybackTimer Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 Dec 07 19:25:45 volumio volumio[1286]: info: [1765157145354] ControllerUPNPBrowser::clearAddPlayTrack Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop Dec 07 19:25:45 volumio volumio[1286]: info: Dec 07 19:25:45 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand stop took 32 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand stop took 6 milliseconds Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand clear Dec 07 19:25:45 volumio volumio[1286]: info: Dec 07 19:25:45 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:45 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand clear took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.1:8200/MediaItems/6073.wav" Dec 07 19:25:45 volumio volumio[1286]: error: updateQueue error: null Dec 07 19:25:45 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:45 volumio volumio[1286]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 07 19:25:45 volumio volumio[1286]: info: ------------------------------ 4ms Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6073.wav" Dec 07 19:25:45 volumio volumio[1286]: info: Dec 07 19:25:45 volumio volumio[1286]: ---------------------------- MPD announces system playlist update Dec 07 19:25:45 volumio volumio[1286]: info: Ignoring MPD Status Update Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand add "http://192.168.1.1:8200/MediaItems/6073.wav" took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand play Dec 07 19:25:45 volumio volumio[1286]: info: ------------------------------ 1ms Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand play took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: Dec 07 19:25:45 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:45 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:45 volumio volumio[1286]: info: Dec 07 19:25:45 volumio volumio[1286]: ---------------------------- MPD announces state update: player Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand status took 3 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: ControllerMpd::getState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand status took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseState Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:45 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 Dec 07 19:25:45 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":270,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6073.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6073.wav","trackType":"wav"} Dec 07 19:25:45 volumio volumio[1286]: verbose: CURRENT POSITION 0 Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop Dec 07 19:25:45 volumio volumio[1286]: info: ------------------------------ 8ms Dec 07 19:25:45 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 07 19:25:45 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo Dec 07 19:25:45 volumio volumio[1286]: info: ControllerMpd::pushState Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::servicePushState Dec 07 19:25:45 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 Dec 07 19:25:45 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":270,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"6073.wav","artist":null,"album":null,"uri":"http://192.168.1.1:8200/MediaItems/6073.wav","trackType":"wav"} Dec 07 19:25:45 volumio volumio[1286]: verbose: CURRENT POSITION 0 Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play Dec 07 19:25:45 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:45 volumio volumio[1286]: info: CoreStateMachine::pushState Dec 07 19:25:45 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output update for this device Dec 07 19:25:45 volumio volumio[1286]: info: MRS: Pushing multiroomSync output Dec 07 19:25:45 volumio volumio[1286]: info: ------------------------------ 29ms Dec 07 19:25:45 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:45 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:45 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:46 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:46 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:46 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:46 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:46 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:47 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:48 volumio wpa_supplicant[950]: RRM: Ignoring radio measurement request: Not RRM network Dec 07 19:25:50 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:50 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:50 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:50 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:50 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:50 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:51 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:51 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:52 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:53 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 07 19:25:53 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:25:54 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:54 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:54 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:25:54 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:55 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:55 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:55 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:55 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:56 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:25:57 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:25:57 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:25:57 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:25:57 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:25:57 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:25:58 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:25:58 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:25:58 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:25:59 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:26:01 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:26:01 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:26:01 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:26:01 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:26:01 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:26:02 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:26:02 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:26:02 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:26:02 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:26:04 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:26:04 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:26:04 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Dec 07 19:26:04 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:26:04 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:26:05 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:26:05 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:26:05 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:26:05 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:26:06 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 07 19:26:07 volumio volumio[1286]: info: Preload queue cleared Dec 07 19:26:08 volumio dhcpcd[962]: eth0: carrier acquired Dec 07 19:26:08 volumio dhcpcd[962]: eth0: IAID 01:3f:49:5f Dec 07 19:26:08 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Dec 07 19:26:08 volumio ifplugd(eth0)[824]: Link beat detected. Dec 07 19:26:09 volumio dhcpcd[962]: eth0: soliciting an IPv6 router Dec 07 19:26:09 volumio dhcpcd[962]: eth0: soliciting a DHCP lease Dec 07 19:26:09 volumio dhcpcd[962]: eth0: carrier lost Dec 07 19:26:09 volumio kernel: bcmgenet fd580000.ethernet eth0: Link is Down Dec 07 19:26:10 volumio ifplugd(eth0)[824]: Link beat lost. Dec 07 19:26:10 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 07 19:26:10 volumio volumio[1286]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:26:10 volumio volumio[1286]: TypeError: Cannot read property 'length' of undefined Dec 07 19:26:10 volumio volumio[1286]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Dec 07 19:26:10 volumio volumio[1286]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Dec 07 19:26:10 volumio volumio[1286]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Dec 07 19:26:10 volumio volumio[1286]: at Parser.emit (events.js:315:20) Dec 07 19:26:10 volumio volumio[1286]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Dec 07 19:26:10 volumio volumio[1286]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Dec 07 19:26:10 volumio volumio[1286]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Dec 07 19:26:10 volumio volumio[1286]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Dec 07 19:26:10 volumio volumio[1286]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Dec 07 19:26:10 volumio volumio[1286]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Dec 07 19:26:10 volumio volumio[1286]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Dec 07 19:26:10 volumio volumio[1286]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Dec 07 19:26:10 volumio volumio[1286]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Dec 07 19:26:10 volumio volumio[1286]: at IncomingMessage.emit (events.js:327:22) Dec 07 19:26:10 volumio volumio[1286]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 07 19:26:10 volumio volumio[1286]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 07 19:26:10 volumio volumio[1286]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 07 19:26:10 volumio sudo[24203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-07 19:25 Dec 07 19:26:10 volumio sudo[24203]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"