-- Logs begin at Thu 2024-10-10 15:42:45 CST, end at Thu 2024-10-10 16:19:50 CST. -- Oct 10 16:18:00 volumio volumio[2539]: info: MyVolumio login type: Token Oct 10 16:18:17 volumio volumio[2539]: info: CoreCommandRouter::volumioGetState Oct 10 16:18:23 volumio volumio[2539]: info: CoreCommandRouter::volumioRandom Oct 10 16:18:23 volumio volumio[2539]: info: CoreCommandRouter::writePlayerControls Oct 10 16:18:23 volumio volumio[2539]: info: CoreStateMachine::setRepeat true single true Oct 10 16:18:23 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:18:23 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:18:23 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:18:30 volumio volumio[2539]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Oct 10 16:18:30 volumio volumio[2539]: info: Retrying Login Due to Network Error Oct 10 16:18:40 volumio volumio[2539]: info: MyVolumio login type: Token Oct 10 16:18:47 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 10 16:18:47 volumio volumio[2539]: info: Preload queue cleared Oct 10 16:18:54 volumio volumio[2539]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Babyface/479833a5-960e-4bb1-b4a8-d2b85228a9a1.jpg' Oct 10 16:18:55 volumio volumio[2539]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/The%20Carpenters/b51d5a7b-67b0-4d7c-bb6e-e385a006f82f.jpg' Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::updateTrackBlock Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrackBlock Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 6 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::serviceStop Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 6 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::serviceStop Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344466] ControllerUPNPBrowser::stop Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 19 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344513] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344514] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344515] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344516] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344522] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 62 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 18 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 16 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 11 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 9 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: [1728548344536] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand status took 15 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand clear took 13 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand clear took 13 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand clear took 14 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand clear took 13 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand stop took 13 milliseconds Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:04 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:04 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:04 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:04 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:04 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 71ms Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 68ms Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 120 milliseconds Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/108.dsd" Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand clear took 114 milliseconds Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/1184.wav" Oct 10 16:19:04 volumio volumio[2539]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 153ms Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand status took 114 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand status took 103 milliseconds Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:04 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: 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} Oct 10 16:19:04 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: No code Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: 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} Oct 10 16:19:04 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: No code Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:04 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:04 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 349ms Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 338ms Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/108.dsd" took 256 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/108.dsd" took 255 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/108.dsd" took 256 milliseconds Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 258ms Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/1184.wav" Oct 10 16:19:04 volumio volumio[2539]: info: ------------------------------ 17ms Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:04 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:04 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:04 volumio volumio[2539]: info: Oct 10 16:19:04 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:04 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:05 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 82ms Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 76ms Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/1184.wav" took 67 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 80ms Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand play took 72 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand play took 70 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand play took 82 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand play took 79 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 83ms Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:05 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:05 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 122ms Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand play took 85 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 81ms Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 88ms Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:05 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:05 volumio volumio[2539]: info: Oct 10 16:19:05 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand status took 66 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand status took 64 milliseconds Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand status took 78 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 78ms Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand status took 77 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 33 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 34 milliseconds Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:05 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:05 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":432,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"108.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/108.dsd","trackType":"dsd"} Oct 10 16:19:05 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:05 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:05 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":443,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"108.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/108.dsd","trackType":"dsd"} Oct 10 16:19:05 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:05 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 201ms Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 224ms Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 91 milliseconds Oct 10 16:19:05 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 92 milliseconds Oct 10 16:19:05 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:05 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:05 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":443,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"108.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/108.dsd","trackType":"dsd"} Oct 10 16:19:05 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:05 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:05 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:05 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":506,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"108.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/108.dsd","trackType":"dsd"} Oct 10 16:19:05 volumio volumio[2539]: verbose: CURRENT POSITION 18 Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:05 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:05 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 326ms Oct 10 16:19:05 volumio volumio[2539]: info: ------------------------------ 316ms Oct 10 16:19:09 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:09 volumio volumio[2539]: info: CoreStateMachine::play index 19 Oct 10 16:19:09 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:09 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::stPlaybackTimer Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::updateTrackBlock Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrackBlock Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::serviceStop Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::serviceStop Oct 10 16:19:10 volumio volumio[2539]: info: [1728548350046] ControllerUPNPBrowser::stop Oct 10 16:19:10 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioRemoveQueueItem Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::removeQueueItem Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::removeQueueItem 19 Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::saveQueue Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioPushQueue Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioRemoveQueueItem Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::removeQueueItem Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::removeQueueItem 19 Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::saveQueue Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioPushQueue Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioPlay Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::play index 20 Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioSeek Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::seek Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:10 volumio volumio[2539]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.3.75:8200/MediaItems/1184.wav","realUri":"upnp/folder/http://192.168.3.75:8200/ctl/ContentDir@1$4","type":"song","albumart":"/albumart?cacheid=851&web=//extralarge&path=&metadata=false","artist":"","album":"","name":"01","title":"01","duration":273} Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:10 volumio volumio[2539]: info: [1728548350208] ControllerUPNPBrowser::seek Oct 10 16:19:10 volumio volumio[2539]: info: ControllerMpd::seek Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 18 Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:10 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::stop Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:10 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:10 volumio volumio[2539]: info: CorePlayQueue::getTrack 20 Oct 10 16:19:10 volumio volumio[2539]: info: [1728548350919] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:10 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:11 volumio volumio[2539]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Oct 10 16:19:11 volumio volumio[2539]: info: Retrying Login Due to Network Error Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: error: null Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand stop took 1546 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand stop took 667 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::play index undefined Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: [1728548351601] ControllerUPNPBrowser::clearAddPlayTrack Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:11 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 28 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 27 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 26 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand clear took 25 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand stop took 23 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 21 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 17 milliseconds Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/153.dsd" Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand clear Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: 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} Oct 10 16:19:11 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: No code Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: 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} Oct 10 16:19:11 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: No code Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: ------------------------------ 160ms Oct 10 16:19:11 volumio volumio[2539]: info: ------------------------------ 159ms Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:11 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:11 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:11 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:11 volumio volumio[2539]: info: Oct 10 16:19:11 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:11 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:11 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:11 volumio volumio[2539]: error: updateQueue error: null Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 160 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: ------------------------------ 164ms Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 152 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 151 milliseconds Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/153.dsd" Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand clear took 155 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: ------------------------------ 22ms Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 20 milliseconds Oct 10 16:19:11 volumio volumio[2539]: info: ------------------------------ 18ms Oct 10 16:19:11 volumio volumio[2539]: info: sendMpdCommand status took 15 milliseconds Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/132.dsd" Oct 10 16:19:11 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: 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} Oct 10 16:19:11 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: No code Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 10 16:19:11 volumio volumio[2539]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 10 16:19:11 volumio volumio[2539]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: 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} Oct 10 16:19:11 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: No code Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: 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} Oct 10 16:19:11 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState stateService stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:11 volumio volumio[2539]: info: No code Oct 10 16:19:11 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:11 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:11 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 437ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 468ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 464ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 465ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 289ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 286ms Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/153.dsd" took 375 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 380ms Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/132.dsd" Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 98ms Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 16ms Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/132.dsd" took 7 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand play Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand play took 13 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 13ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 12ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 9ms Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand play took 7 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:12 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 3ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 4ms Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 51 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 47 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 41 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: info: Oct 10 16:19:12 volumio volumio[2539]: ---------------------------- MPD announces state update: player Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::getState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand status Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 39 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus stop Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:12 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:12 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 141ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 187ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 178ms Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 124 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand status took 119 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 90 milliseconds Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseState Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":56,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:12 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 189ms Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 67 milliseconds Oct 10 16:19:12 volumio volumio[2539]: info: sendMpdCommand playlistinfo took 67 milliseconds Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:12 volumio volumio[2539]: verbose: ControllerMpd::parseTrackInfo Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":56,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:12 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ControllerMpd::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::servicePushState Oct 10 16:19:12 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:12 volumio volumio[2539]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73,"duration":83,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"153.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/153.dsd","trackType":"dsd"} Oct 10 16:19:12 volumio volumio[2539]: verbose: CURRENT POSITION 19 Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState stateService play Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::syncState currentStatus play Oct 10 16:19:12 volumio volumio[2539]: info: Received an update from plugin. extracting info from payload Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:12 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 283ms Oct 10 16:19:12 volumio volumio[2539]: info: ------------------------------ 280ms Oct 10 16:19:21 volumio volumio[2539]: info: MyVolumio login type: Token Oct 10 16:19:30 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:30 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:30 volumio volumio[2539]: info: Prefetching next song Oct 10 16:19:30 volumio volumio[2539]: info: Doing Prefetch in UPNP Oct 10 16:19:30 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/132.dsd" Oct 10 16:19:30 volumio volumio[2539]: info: Oct 10 16:19:30 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:30 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:30 volumio volumio[2539]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/132.dsd" took 12 milliseconds Oct 10 16:19:30 volumio volumio[2539]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 10 16:19:30 volumio volumio[2539]: info: Oct 10 16:19:30 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:30 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:30 volumio volumio[2539]: info: Oct 10 16:19:30 volumio volumio[2539]: ---------------------------- MPD announces system playlist update Oct 10 16:19:30 volumio volumio[2539]: info: Ignoring MPD Status Update Oct 10 16:19:30 volumio volumio[2539]: info: ------------------------------ 23ms Oct 10 16:19:30 volumio volumio[2539]: info: sendMpdCommand consume 1 took 16 milliseconds Oct 10 16:19:30 volumio volumio[2539]: info: ------------------------------ 16ms Oct 10 16:19:30 volumio volumio[2539]: info: ------------------------------ 26ms Oct 10 16:19:33 volumio volumio[2539]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 10 16:19:33 volumio volumio[2539]: info: CoreCommandRouter::volumioGetState Oct 10 16:19:33 volumio volumio[2539]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Earth%2C%20Wind%20%26%20Fire/3abd11f9-519d-4c02-8462-f137b5fc78ce.jpg' Oct 10 16:19:34 volumio volumio[2539]: info: CoreStateMachine::startPlaybackTimer Oct 10 16:19:34 volumio volumio[2539]: info: CorePlayQueue::getTrack 19 Oct 10 16:19:35 volumio volumio[2539]: info: CoreStateMachine::pushState Oct 10 16:19:35 volumio volumio[2539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 16:19:35 volumio volumio[2539]: info: CoreCommandRouter::volumioPushState Oct 10 16:19:49 volumio volumio[2539]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 16:19:49 volumio volumio[2539]: Error: connect ETIMEDOUT 168.143.162.58:80 Oct 10 16:19:49 volumio volumio[2539]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Oct 10 16:19:49 volumio volumio[2539]: errno: -110, Oct 10 16:19:49 volumio volumio[2539]: code: 'ETIMEDOUT', Oct 10 16:19:49 volumio volumio[2539]: syscall: 'connect', Oct 10 16:19:49 volumio volumio[2539]: address: '168.143.162.58', Oct 10 16:19:49 volumio volumio[2539]: port: 80 Oct 10 16:19:49 volumio volumio[2539]: } Oct 10 16:19:49 volumio volumio[2539]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 16:19:50 volumio sudo[4418]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-10 16:18 Oct 10 16:19:50 volumio sudo[4418]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:48:50 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1049be5fd382035818795b7f5c38e10d"