-- Logs begin at Tue 2024-05-07 22:44:36 CST, end at Wed 2024-05-08 20:40:12 CST. -- May 08 20:39:03 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 08 20:39:03 volumio volumio[629]: info: Preload queue cleared May 08 20:39:05 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 08 20:39:05 volumio volumio[629]: info: Preload queue cleared May 08 20:39:07 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 08 20:39:07 volumio volumio[629]: info: Preload queue cleared May 08 20:39:09 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 08 20:39:09 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 08 20:39:12 volumio volumio[629]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 08 20:39:12 volumio volumio[629]: info: Retrying Login Due to Network Error May 08 20:39:18 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 08 20:39:18 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 08 20:39:20 volumio sudo[2289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 20:39:20 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 20:39:20 volumio sudo[2291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 20:39:20 volumio sudo[2291]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 20:39:20 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root May 08 20:39:20 volumio sudo[2291]: pam_unix(sudo:session): session closed for user root May 08 20:39:20 volumio volumio[629]: verbose: New Socket.io Connection to 192.168.11.146 from 192.168.11.140 UA: okhttp/4.9.2 Total Clients: 5 May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::volumioGetVisibleSources May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::volumioGetState May 08 20:39:20 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 08 20:39:21 volumio volumio[629]: info: Received Get System Info May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 08 20:39:21 volumio volumio[629]: info: Discovery: Getting this device information May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::volumioGetState May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::volumioGetState May 08 20:39:21 volumio volumio[629]: info: Listing playlists May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 08 20:39:21 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 08 20:39:22 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 08 20:39:22 volumio volumio[629]: info: Received Get System Info May 08 20:39:22 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 08 20:39:22 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 08 20:39:22 volumio volumio[629]: info: Discovery: Getting this device information May 08 20:39:22 volumio volumio[629]: info: CoreCommandRouter::volumioGetState May 08 20:39:22 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 08 20:39:22 volumio volumio[629]: info: MyVolumio login type: Token May 08 20:39:23 volumio volumio[629]: info: CoreCommandRouter::volumioGetQueue May 08 20:39:23 volumio volumio[629]: info: CoreStateMachine::getQueue May 08 20:39:23 volumio volumio[629]: info: CorePlayQueue::getQueue May 08 20:39:29 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 08 20:39:29 volumio volumio[629]: info: Preload queue cleared May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7864580 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7274756 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7078148 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$6947076 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7667972 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7536900 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7602436 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7405828 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7209220 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7340292 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7012612 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7143684 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7799044 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7733508 May 08 20:39:29 volumio volumio[629]: info: Preloading song: upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7471364 May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7864580 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7274756 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7078148 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$6947076 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7667972 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7536900 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7602436 in service upnp_browser May 08 20:39:29 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7405828 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7209220 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7340292 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7012612 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7143684 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7799044 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7733508 in service upnp_browser May 08 20:39:30 volumio volumio[629]: info: Exploding uri upnp/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477$7471364 in service upnp_browser May 08 20:39:31 volumio volumio[629]: info: Preload queue cleared May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioReplaceandPlayItems May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::ClearQueue May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::stop May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::stPlaybackTimer May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::updateTrackBlock May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrackBlock May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::serviceStop May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::serviceStop May 08 20:39:31 volumio volumio[629]: info: [1715171971578] ControllerUPNPBrowser::stop May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand stop May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::clearPlayQueue May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::saveQueue May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushQueue May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::addQueueItems May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::addQueueItems May 08 20:39:31 volumio volumio[629]: info: Preload queue cleared May 08 20:39:31 volumio volumio[629]: info: Adding Item to queue: upnp/folder/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477 May 08 20:39:31 volumio volumio[629]: info: Exploding uri upnp/folder/http://192.168.11.2:8200/ctl/ContentDir@A0$128$146$12914917653$12915507477 in service upnp_browser May 08 20:39:31 volumio volumio[629]: info: May 08 20:39:31 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand stop took 149 milliseconds May 08 20:39:31 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:31 volumio volumio[629]: info: May 08 20:39:31 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:31 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:31 volumio volumio[629]: info: May 08 20:39:31 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:31 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand status took 40 milliseconds May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand status took 27 milliseconds May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand status took 21 milliseconds May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand playlistinfo took 29 milliseconds May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand playlistinfo took 30 milliseconds May 08 20:39:31 volumio volumio[629]: info: sendMpdCommand playlistinfo took 21 milliseconds May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:31 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:31 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mpeg,pn=MP3,ext=.mp3","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915376405$5701892.mp3?type=1,client=33,mime=audio/mpeg,pn=MP3,ext=.mp3","trackType":"mp3"} May 08 20:39:31 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:31 volumio volumio[629]: info: No code May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:31 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mpeg,pn=MP3,ext=.mp3","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915376405$5701892.mp3?type=1,client=33,mime=audio/mpeg,pn=MP3,ext=.mp3","trackType":"mp3"} May 08 20:39:31 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:31 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:31 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:31 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:32 volumio volumio[629]: info: No code May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:32 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mpeg,pn=MP3,ext=.mp3","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915376405$5701892.mp3?type=1,client=33,mime=audio/mpeg,pn=MP3,ext=.mp3","trackType":"mp3"} May 08 20:39:32 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:32 volumio volumio[629]: info: No code May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:32 volumio volumio[629]: info: ------------------------------ 827ms May 08 20:39:32 volumio volumio[629]: info: ------------------------------ 820ms May 08 20:39:32 volumio volumio[629]: info: ------------------------------ 813ms May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPushQueue May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::saveQueue May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::updateTrackBlock May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrackBlock May 08 20:39:32 volumio volumio[629]: info: CoreCommandRouter::volumioPlay May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::play index 0 May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::stop May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::play index undefined May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: CoreStateMachine::startPlaybackTimer May 08 20:39:32 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:32 volumio volumio[629]: info: [1715171972824] ControllerUPNPBrowser::clearAddPlayTrack May 08 20:39:32 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand stop May 08 20:39:32 volumio volumio[629]: info: sendMpdCommand stop took 42 milliseconds May 08 20:39:32 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand clear May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand clear took 242 milliseconds May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: error: updateQueue error: null May 08 20:39:33 volumio volumio[629]: error: updateQueue error: null May 08 20:39:33 volumio volumio[629]: error: updateQueue error: null May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 114ms May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 54ms May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 46ms May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" took 55 milliseconds May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService mpd May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand play May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:33 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 95ms May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand play took 83 milliseconds May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 43ms May 08 20:39:33 volumio volumio[629]: info: ------------------------------ 47ms May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand status took 112 milliseconds May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand status took 92 milliseconds May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: May 08 20:39:33 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand status took 227 milliseconds May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand status took 186 milliseconds May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand playlistinfo took 131 milliseconds May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand playlistinfo took 119 milliseconds May 08 20:39:33 volumio volumio[629]: info: sendMpdCommand status took 84 milliseconds May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:33 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:33 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:33 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:33 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:33 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:33 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:33 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:33 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:33 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:33 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:33 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:33 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:33 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:33 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: ------------------------------ 633ms May 08 20:39:34 volumio volumio[629]: info: ------------------------------ 910ms May 08 20:39:34 volumio volumio[629]: info: sendMpdCommand status took 729 milliseconds May 08 20:39:34 volumio volumio[629]: info: sendMpdCommand playlistinfo took 665 milliseconds May 08 20:39:34 volumio volumio[629]: info: sendMpdCommand playlistinfo took 654 milliseconds May 08 20:39:34 volumio volumio[629]: info: sendMpdCommand playlistinfo took 637 milliseconds May 08 20:39:34 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:34 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:34 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:34 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:34 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:34 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:34 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:34 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:34 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:34 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:34 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:34 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:34 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:34 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:34 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:34 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:35 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:35 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:35 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:35 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:35 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:35 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:35 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:35 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:35 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:35 volumio volumio[629]: info: ------------------------------ 2213ms May 08 20:39:35 volumio volumio[629]: info: ------------------------------ 2186ms May 08 20:39:35 volumio volumio[629]: info: ------------------------------ 2064ms May 08 20:39:36 volumio volumio[629]: info: sendMpdCommand playlistinfo took 1633 milliseconds May 08 20:39:36 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:36 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:36 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:36 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:36 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7864580.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:36 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:36 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:36 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:36 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:36 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:36 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:36 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:36 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:36 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:36 volumio volumio[629]: info: ------------------------------ 2605ms May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::volumioNext May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::next May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::next May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand next May 08 20:39:43 volumio volumio[629]: info: May 08 20:39:43 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:43 volumio volumio[629]: info: sendMpdCommand next took 30 milliseconds May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:43 volumio volumio[629]: info: May 08 20:39:43 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:43 volumio volumio[629]: info: May 08 20:39:43 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:43 volumio volumio[629]: info: sendMpdCommand status took 82 milliseconds May 08 20:39:43 volumio volumio[629]: info: sendMpdCommand status took 67 milliseconds May 08 20:39:43 volumio volumio[629]: info: sendMpdCommand status took 41 milliseconds May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:43 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:43 volumio volumio[629]: info: CorePlayQueue::getTrack 0 May 08 20:39:43 volumio volumio[629]: 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} May 08 20:39:43 volumio volumio[629]: verbose: CURRENT POSITION 0 May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::play index undefined May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:43 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:43 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:43 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:43 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:43 volumio volumio[629]: 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} May 08 20:39:43 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:43 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:43 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:43 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:44 volumio volumio[629]: info: No code May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:44 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: 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} May 08 20:39:44 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:44 volumio volumio[629]: info: No code May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::startPlaybackTimer May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: [1715171984927] ControllerUPNPBrowser::clearAddPlayTrack May 08 20:39:44 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand stop May 08 20:39:44 volumio volumio[629]: info: ------------------------------ 1506ms May 08 20:39:44 volumio volumio[629]: info: ------------------------------ 1467ms May 08 20:39:44 volumio volumio[629]: info: ------------------------------ 1446ms May 08 20:39:44 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:44 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:44 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand stop took 196 milliseconds May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand clear May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand clear took 292 milliseconds May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: error: updateQueue error: null May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 95ms May 08 20:39:45 volumio volumio[629]: error: updateQueue error: null May 08 20:39:45 volumio volumio[629]: error: updateQueue error: null May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 73ms May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 50ms May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" took 31 milliseconds May 08 20:39:45 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService mpd May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand play May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:45 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 81ms May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand play took 69 milliseconds May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 64ms May 08 20:39:45 volumio volumio[629]: info: ------------------------------ 44ms May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand status took 127 milliseconds May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand status took 97 milliseconds May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: May 08 20:39:45 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:45 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:45 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:45 volumio volumio[629]: info: sendMpdCommand status took 114 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand status took 101 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand playlistinfo took 77 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand playlistinfo took 75 milliseconds May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:46 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:46 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:46 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:46 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:46 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:46 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:46 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:46 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:46 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:46 volumio volumio[629]: info: ------------------------------ 547ms May 08 20:39:46 volumio volumio[629]: info: ------------------------------ 707ms May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand status took 578 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand status took 574 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand playlistinfo took 533 milliseconds May 08 20:39:46 volumio volumio[629]: info: sendMpdCommand playlistinfo took 530 milliseconds May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:46 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:46 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:46 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:46 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:46 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:46 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:46 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:46 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:46 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:46 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:46 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:46 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:46 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:47 volumio volumio[629]: info: ------------------------------ 1481ms May 08 20:39:47 volumio volumio[629]: info: ------------------------------ 1434ms May 08 20:39:47 volumio volumio[629]: info: sendMpdCommand playlistinfo took 1018 milliseconds May 08 20:39:47 volumio volumio[629]: info: sendMpdCommand playlistinfo took 1026 milliseconds May 08 20:39:47 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:47 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:47 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:47 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:47 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:47 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:47 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:47 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:47 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:47 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":292,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7274756.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:47 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:47 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:47 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:47 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: ------------------------------ 2342ms May 08 20:39:48 volumio volumio[629]: info: ------------------------------ 2329ms May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioNext May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::next May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::next May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand next May 08 20:39:48 volumio volumio[629]: info: May 08 20:39:48 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:48 volumio volumio[629]: info: sendMpdCommand next took 33 milliseconds May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:48 volumio volumio[629]: info: May 08 20:39:48 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:48 volumio volumio[629]: info: May 08 20:39:48 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:48 volumio volumio[629]: info: sendMpdCommand status took 37 milliseconds May 08 20:39:48 volumio volumio[629]: info: sendMpdCommand status took 27 milliseconds May 08 20:39:48 volumio volumio[629]: info: sendMpdCommand status took 17 milliseconds May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:48 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 1 May 08 20:39:48 volumio volumio[629]: 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} May 08 20:39:48 volumio volumio[629]: verbose: CURRENT POSITION 1 May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::play index undefined May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService undefined May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: 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} May 08 20:39:48 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: No code May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: 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} May 08 20:39:48 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState stateService stop May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:48 volumio volumio[629]: info: No code May 08 20:39:48 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:48 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:48 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:49 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:49 volumio volumio[629]: info: CoreStateMachine::startPlaybackTimer May 08 20:39:49 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:49 volumio volumio[629]: info: [1715171989174] ControllerUPNPBrowser::clearAddPlayTrack May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand stop May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 680ms May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 671ms May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 666ms May 08 20:39:49 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:49 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:49 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:49 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:49 volumio volumio[629]: info: sendMpdCommand stop took 194 milliseconds May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand clear May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: info: sendMpdCommand clear took 207 milliseconds May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: error: updateQueue error: null May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 79ms May 08 20:39:49 volumio volumio[629]: error: updateQueue error: null May 08 20:39:49 volumio volumio[629]: error: updateQueue error: null May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 88ms May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 71ms May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: info: sendMpdCommand add "http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf" took 21 milliseconds May 08 20:39:49 volumio volumio[629]: info: CoreStateMachine::setConsumeUpdateService mpd May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand play May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces system playlist update May 08 20:39:49 volumio volumio[629]: info: Ignoring MPD Status Update May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 223ms May 08 20:39:49 volumio volumio[629]: info: sendMpdCommand play took 212 milliseconds May 08 20:39:49 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:49 volumio volumio[629]: info: ------------------------------ 92ms May 08 20:39:49 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:49 volumio volumio[629]: info: May 08 20:39:49 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:49 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:49 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:50 volumio volumio[629]: info: ------------------------------ 127ms May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand status took 68 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand status took 64 milliseconds May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:50 volumio volumio[629]: info: May 08 20:39:50 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:50 volumio volumio[629]: info: May 08 20:39:50 volumio volumio[629]: ---------------------------- MPD announces state update: player May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::getState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand status May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand status took 158 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand playlistinfo took 123 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand playlistinfo took 121 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand status took 81 milliseconds May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:50 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:50 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:50 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus stop May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:50 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:50 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:50 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:50 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:50 volumio volumio[629]: info: ------------------------------ 541ms May 08 20:39:50 volumio volumio[629]: info: ------------------------------ 731ms May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand status took 540 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand playlistinfo took 481 milliseconds May 08 20:39:50 volumio volumio[629]: info: sendMpdCommand playlistinfo took 468 milliseconds May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseState May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:50 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:50 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:50 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:50 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:50 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:50 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:50 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:50 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:50 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:50 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:50 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:50 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:51 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:51 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:51 volumio volumio[629]: info: ------------------------------ 1814ms May 08 20:39:51 volumio volumio[629]: info: ------------------------------ 1727ms May 08 20:39:52 volumio volumio[629]: info: sendMpdCommand playlistinfo took 1362 milliseconds May 08 20:39:52 volumio volumio[629]: verbose: ControllerMpd::parseTrackInfo May 08 20:39:52 volumio volumio[629]: info: ControllerMpd::pushState May 08 20:39:52 volumio volumio[629]: info: CoreCommandRouter::servicePushState May 08 20:39:52 volumio volumio[629]: info: CorePlayQueue::getTrack 2 May 08 20:39:52 volumio volumio[629]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":256,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"x-ms-wma,pn=WMABASE,ext=.asf","artist":null,"album":null,"uri":"http://192.168.11.2:8200/MediaItems/A0$128$146$12914917653$12915507477$7078148.asf?type=1,client=33,mime=audio/x-ms-wma,pn=WMABASE,ext=.asf","trackType":"asf"} May 08 20:39:52 volumio volumio[629]: verbose: CURRENT POSITION 2 May 08 20:39:52 volumio volumio[629]: info: CoreStateMachine::syncState stateService play May 08 20:39:52 volumio volumio[629]: info: CoreStateMachine::syncState currentStatus play May 08 20:39:52 volumio volumio[629]: info: Received an update from plugin. extracting info from payload May 08 20:39:52 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:52 volumio volumio[629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 20:39:52 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:52 volumio volumio[629]: info: CoreStateMachine::pushState May 08 20:39:52 volumio volumio[629]: info: CoreCommandRouter::volumioPushState May 08 20:39:52 volumio volumio[629]: info: ------------------------------ 2156ms May 08 20:39:52 volumio volumio[629]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 08 20:39:52 volumio volumio[629]: info: Retrying Login Due to Network Error May 08 20:40:02 volumio volumio[629]: info: MyVolumio login type: Token May 08 20:40:06 volumio volumio[629]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 08 20:40:07 volumio volumio[629]: info: Retrying Login Due to Network Error May 08 20:40:08 volumio volumio[629]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 20:40:08 volumio volumio[629]: Error: connect ETIMEDOUT 74.86.118.24:443 May 08 20:40:08 volumio volumio[629]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 08 20:40:08 volumio volumio[629]: errno: -110, May 08 20:40:08 volumio volumio[629]: code: 'ETIMEDOUT', May 08 20:40:08 volumio volumio[629]: syscall: 'connect', May 08 20:40:08 volumio volumio[629]: address: '74.86.118.24', May 08 20:40:08 volumio volumio[629]: port: 443 May 08 20:40:08 volumio volumio[629]: } May 08 20:40:08 volumio volumio[629]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 20:40:12 volumio sudo[2424]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 20:39 May 08 20:40:12 volumio sudo[2424]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"