-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Fri 2025-07-18 23:48:42 CST. -- Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioSeek Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::seek Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:47:00 volumio volumio[2226]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.0.108:8200/MediaItems/814.flac","realUri":"upnp/http://192.168.0.108:8200/ctl/ContentDir@1$4$54","type":"song","albumart":"http://192.168.0.108:8200/AlbumArt/49-814.jpg","artist":"G.E.M.邓紫棋","album":"新的心跳","name":"多远都要在一起","title":"多远都要在一起","duration":217} Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::startPlaybackTimer Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:47:00 volumio volumio[2226]: info: [1752853620223] ControllerUPNPBrowser::seek Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::seek Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: error: null Jul 18 23:47:00 volumio volumio[2226]: info: Jul 18 23:47:00 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: Jul 18 23:47:00 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:47:00 volumio volumio[2226]: info: Jul 18 23:47:00 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand status took 9 milliseconds Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:47:00 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":59000,"duration":218,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5286 Kbps","isStreaming":false,"title":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:47:00 volumio volumio[2226]: verbose: CURRENT POSITION 34 Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:47:00 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:47:00 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":59000,"duration":218,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5286 Kbps","isStreaming":false,"title":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:47:00 volumio volumio[2226]: verbose: CURRENT POSITION 34 Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:47:00 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: ------------------------------ 54ms Jul 18 23:47:00 volumio volumio[2226]: info: ------------------------------ 48ms Jul 18 23:47:00 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 44 milliseconds Jul 18 23:47:00 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:47:00 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:47:00 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":59000,"duration":218,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5286 Kbps","isStreaming":false,"title":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:47:00 volumio volumio[2226]: verbose: CURRENT POSITION 34 Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:47:00 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:47:00 volumio volumio[2226]: info: ------------------------------ 71ms Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:00 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:00 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:01 volumio volumio[2226]: info: Adding http://192.168.0.108:8200/MediaItems/814.flac to favourites using generic method Jul 18 23:47:01 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , lsInfo Jul 18 23:47:01 volumio volumio[2226]: error: Failed LSINFO: Error: [52@0] {lsinfo} Failed to access /192.168.0.108:8200/MediaItems/814.flac: No such file or directory Jul 18 23:47:01 volumio volumio[2226]: info: Saving local item favourites Jul 18 23:47:01 volumio volumio[2226]: info: Pushing Favourites {"uri":"http://192.168.0.108:8200/MediaItems/814.flac","favourite":false} Jul 18 23:47:05 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , lsInfo Jul 18 23:47:05 volumio volumio[2226]: error: Failed LSINFO: Error: [52@0] {lsinfo} Failed to access /192.168.0.108:8200/MediaItems/814.flac: No such file or directory Jul 18 23:47:05 volumio volumio[2226]: info: Saving local item undefined Jul 18 23:47:05 volumio volumio[2226]: info: Pushing Favourites {"uri":"http://192.168.0.108:8200/MediaItems/814.flac","favourite":false} Jul 18 23:47:05 volumio volumio[2226]: info: Listing playlists Jul 18 23:47:13 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , lsInfo Jul 18 23:47:13 volumio volumio[2226]: error: Failed LSINFO: Error: [52@0] {lsinfo} Failed to access /192.168.0.108:8200/MediaItems/814.flac: No such file or directory Jul 18 23:47:13 volumio volumio[2226]: info: Saving local item undefined Jul 18 23:47:13 volumio volumio[2226]: info: Pushing Favourites {"uri":"http://192.168.0.108:8200/MediaItems/814.flac","favourite":false} Jul 18 23:47:13 volumio volumio[2226]: info: Listing playlists Jul 18 23:47:16 volumio ntpd[779]: 193.182.111.143 local addr 192.168.0.104 -> Jul 18 23:47:18 volumio volumio[2226]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jul 18 23:47:18 volumio volumio[2226]: info: Retrying Login Due to Network Error Jul 18 23:47:21 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 18 23:47:21 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 18 23:47:23 volumio sudo[3582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 23:47:23 volumio sudo[3582]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 23:47:23 volumio sudo[3582]: pam_unix(sudo:session): session closed for user root Jul 18 23:47:23 volumio sudo[3584]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 23:47:23 volumio sudo[3584]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 23:47:23 volumio sudo[3584]: pam_unix(sudo:session): session closed for user root Jul 18 23:47:23 volumio volumio[2226]: verbose: New Socket.io Connection to 192.168.0.104 from 192.168.0.102 UA: okhttp/4.9.2 Engine version: 3 Transport: polling Total Clients: 6 Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::volumioGetState Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 18 23:47:23 volumio volumio[2226]: info: Listing playlists Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 18 23:47:23 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 18 23:47:26 volumio volumio[2226]: info: CoreCommandRouter::volumioGetVisibleSources Jul 18 23:47:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 23:47:26 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:47:26 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:47:26 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:47:28 volumio volumio[2226]: info: MyVolumio login type: Token Jul 18 23:47:29 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 18 23:47:29 volumio volumio[2226]: info: CURURI: playlists Jul 18 23:47:29 volumio volumio[2226]: info: Listing playlists Jul 18 23:47:29 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:30 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 18 23:47:30 volumio volumio[2226]: info: CURURI: playlists/undefined Jul 18 23:47:30 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:35 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 18 23:47:35 volumio volumio[2226]: info: CURURI: music-library Jul 18 23:47:35 volumio volumio[2226]: error: Failed LSINFO: null Jul 18 23:47:35 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:40 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jul 18 23:47:40 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:46 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:52 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:47:52 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:53 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:47:53 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:54 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:47:54 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 Jul 18 23:47:54 volumio volumio[2226]: info: Preloading song: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A in service upnp_browser Jul 18 23:47:54 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 in service upnp_browser Jul 18 23:47:55 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 in service upnp_browser Jul 18 23:47:55 volumio volumio[2226]: info: Exploding uri upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 in service upnp_browser Jul 18 23:47:58 volumio volumio[2226]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jul 18 23:47:58 volumio volumio[2226]: info: Retrying Login Due to Network Error Jul 18 23:47:59 volumio ntpd[779]: 193.182.111.12 local addr 192.168.0.104 -> Jul 18 23:48:00 volumio volumio[2226]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E8%93%9D%E5%BF%83%E7%BE%BD/%E9%98%BF%E6%8B%89%E6%96%AF%E5%8A%A0%E6%B5%B7%E6%B9%BE/4717db99-2da8-427f-82da-8b2d5d2ff004.jpg' Jul 18 23:48:00 volumio volumio[2226]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%88%98%E5%85%86%E5%AE%87/%E5%86%AC%E7%9C%A0%C2%B72023/cee817e3-1407-4cef-a6ed-3f2bea4d41b2.jpg' Jul 18 23:48:06 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::ClearQueue Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::stPlaybackTimer Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::serviceStop Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::serviceStop Jul 18 23:48:06 volumio volumio[2226]: info: [1752853686585] ControllerUPNPBrowser::stop Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::clearPlayQueue Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::addQueueItems Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::addQueueItems Jul 18 23:48:06 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2E Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2E in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2F Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2F in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$30 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$30 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$32 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$32 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$33 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$33 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$34 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$34 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$35 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$35 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$37 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$37 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$39 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$39 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3A Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3A in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3C Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3C in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3D Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3D in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3E Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3E in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$31 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$31 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$38 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$38 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3B Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3B in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$28 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$28 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$E Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$E in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$6 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$6 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$13 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$13 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$21 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$21 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$23 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$23 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$10 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$10 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2D Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2D in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$14 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$14 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2B Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2B in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$22 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$22 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$27 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$27 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$26 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$26 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$25 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$25 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$17 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$17 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1A Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1A in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2A Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2A in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$20 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$20 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1F Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1F in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1E Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1E in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$C Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$C in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$F Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$F in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$18 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$18 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$11 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$11 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$15 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$15 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$7 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$7 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$8 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$8 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$29 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$29 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1C Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1C in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$19 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$19 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2C Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2C in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$12 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$12 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$4 Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$4 in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$B Jul 18 23:48:06 volumio volumio[2226]: info: Exploding uri upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$B in service upnp_browser Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 Jul 18 23:48:06 volumio volumio[2226]: info: Jul 18 23:48:06 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand stop took 99 milliseconds Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:06 volumio volumio[2226]: info: Jul 18 23:48:06 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:06 volumio volumio[2226]: info: Jul 18 23:48:06 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand status took 16 milliseconds Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand status took 47 milliseconds Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 47 milliseconds Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 46 milliseconds Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: 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":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:48:06 volumio volumio[2226]: verbose: CURRENT POSITION 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: No code Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: 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":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:48:06 volumio volumio[2226]: verbose: CURRENT POSITION 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: No code Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 34 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: ------------------------------ 94ms Jul 18 23:48:06 volumio volumio[2226]: info: ------------------------------ 80ms Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPlay Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::play index 59 Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::addQueueItems Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::addQueueItems Jul 18 23:48:06 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 Jul 18 23:48:06 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 Jul 18 23:48:06 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 59 Jul 18 23:48:06 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 95 milliseconds Jul 18 23:48:06 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:06 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:06 volumio volumio[2226]: 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":"多远都要在一起","artist":"G.E.M.邓紫棋","album":"新的心跳","uri":"http://192.168.0.108:8200/MediaItems/814.flac","trackType":"flac"} Jul 18 23:48:06 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: No code Jul 18 23:48:06 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:06 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:06 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:06 volumio volumio[2226]: info: ------------------------------ 160ms Jul 18 23:48:08 volumio volumio[2226]: info: MyVolumio login type: Token Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPlay Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::startPlaybackTimer Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: info: [1752853688899] ControllerUPNPBrowser::clearAddPlayTrack Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand stop took 1 milliseconds Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand clear Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand clear took 1 milliseconds Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.108:8200/MediaItems/785.flac" Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 3ms Jul 18 23:48:08 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:08 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.108:8200/MediaItems/785.flac" Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 22ms Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 21ms Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand add "http://192.168.0.108:8200/MediaItems/785.flac" took 1 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand play Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand play took 2 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand status took 6 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand status took 5 milliseconds Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:08 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:08 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:08 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:08 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:08 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 21ms Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 42ms Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 41ms Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:08 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand status took 36 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 34 milliseconds Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:08 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:08 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:08 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:08 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:08 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:08 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:08 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:08 volumio volumio[2226]: info: ------------------------------ 61ms Jul 18 23:48:08 volumio volumio[2226]: info: Jul 18 23:48:08 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:09 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:09 volumio volumio[2226]: info: Jul 18 23:48:09 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:09 volumio volumio[2226]: info: Jul 18 23:48:09 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:09 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:09 volumio volumio[2226]: info: Jul 18 23:48:09 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 31ms Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand status took 29 milliseconds Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 29 milliseconds Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 30 milliseconds Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 5ms Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:09 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:09 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:09 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:09 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:09 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:09 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 96ms Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 95ms Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 32ms Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand status took 32 milliseconds Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 29 milliseconds Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 29 milliseconds Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:09 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:09 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:09 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:09 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:09 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:09 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 90ms Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 65ms Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 65 milliseconds Jul 18 23:48:09 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:09 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:09 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:09 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:09 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:09 volumio volumio[2226]: info: ------------------------------ 112ms Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:09 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:09 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:18 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::ClearQueue Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::stop Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::stPlaybackTimer Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::serviceStop Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::serviceStop Jul 18 23:48:18 volumio volumio[2226]: info: [1752853698966] ControllerUPNPBrowser::stop Jul 18 23:48:18 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::clearPlayQueue Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::addQueueItems Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::addQueueItems Jul 18 23:48:18 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2E Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2E Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2F Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2F Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$30 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$30 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$32 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$32 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$33 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$33 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$34 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$34 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$35 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$35 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$37 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$37 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$39 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$39 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3A Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3A Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3C Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3C Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3D Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3D Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3E Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3E Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$31 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$31 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$38 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$38 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3B Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$3B Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$28 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$28 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$E Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$E Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$6 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$6 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$13 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$13 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$21 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$21 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$23 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$23 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$10 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$10 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2D Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2D Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$14 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$14 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2B Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2B Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$22 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$22 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$27 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$27 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$26 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$26 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$25 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$25 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$17 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$17 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1A Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1A Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2A Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2A Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$20 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$20 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1F Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1F Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1E Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1E Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$C Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$C Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$F Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$F Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$18 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$18 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$11 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$11 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$15 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$15 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$7 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$7 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$8 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$8 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$29 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$29 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1C Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$1C Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$19 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$19 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2C Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$2C Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$12 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$12 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$4 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$4 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$B Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/folder/http://192.168.0.108:8200/ctl/ContentDir@64$B Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$46 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$48 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$47 Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioPlay Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::play index 52 Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::addQueueItems Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::addQueueItems Jul 18 23:48:18 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4D Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4C Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4B Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$44 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4E Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$4A Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$43 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$49 Jul 18 23:48:18 volumio volumio[2226]: info: Adding Item to queue: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 Jul 18 23:48:18 volumio volumio[2226]: info: Using cached record of: upnp/http://192.168.0.108:8200/ctl/ContentDir@64$45 Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::stop Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:18 volumio volumio[2226]: info: CoreCommandRouter::volumioPushQueue Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::saveQueue Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:18 volumio volumio[2226]: info: CoreStateMachine::updateTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrackBlock Jul 18 23:48:18 volumio volumio[2226]: info: CorePlayQueue::getTrack 52 Jul 18 23:48:19 volumio volumio[2226]: info: Jul 18 23:48:19 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand stop took 57 milliseconds Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:19 volumio volumio[2226]: info: Jul 18 23:48:19 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:19 volumio volumio[2226]: info: Jul 18 23:48:19 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: 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":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:19 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: No code Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: 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":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:19 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: No code Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: ------------------------------ 35ms Jul 18 23:48:19 volumio volumio[2226]: info: ------------------------------ 34ms Jul 18 23:48:19 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 32 milliseconds Jul 18 23:48:19 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:19 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: 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":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:19 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: No code Jul 18 23:48:19 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:19 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:19 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:19 volumio volumio[2226]: info: ------------------------------ 50ms Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPlay Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::startPlaybackTimer Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: info: [1752853701366] ControllerUPNPBrowser::clearAddPlayTrack Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand stop took 1 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand clear Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand clear took 1 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.108:8200/MediaItems/785.flac" Jul 18 23:48:21 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.108:8200/MediaItems/785.flac" Jul 18 23:48:21 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:21 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 18ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 17ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand add "http://192.168.0.108:8200/MediaItems/785.flac" took 1 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand play Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand play took 2 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 3 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 8 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 7 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 3 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 12ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 6 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 63ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 63ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 61ms Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 52 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"785.flac","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 82ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 81ms Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:21 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:21 volumio volumio[2226]: info: Jul 18 23:48:21 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 31ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 31 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 4ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 3 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 45ms Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 16ms Jul 18 23:48:21 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 11 milliseconds Jul 18 23:48:21 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:21 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:21 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":513,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1376 Kbps","isStreaming":false,"title":"Interstellar","artist":"Mesarthim","album":"Isolate","uri":"http://192.168.0.108:8200/MediaItems/785.flac","trackType":"flac"} Jul 18 23:48:21 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:21 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:21 volumio volumio[2226]: info: ------------------------------ 23ms Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:21 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:21 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioNext Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::next Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::next Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand next Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand next took 41 milliseconds Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 0 Jul 18 23:48:24 volumio volumio[2226]: 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} Jul 18 23:48:24 volumio volumio[2226]: verbose: CURRENT POSITION 0 Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: 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} Jul 18 23:48:24 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: No code Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::startPlaybackTimer Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: [1752853704975] ControllerUPNPBrowser::clearAddPlayTrack Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:24 volumio volumio[2226]: info: ------------------------------ 13ms Jul 18 23:48:24 volumio volumio[2226]: info: ------------------------------ 12ms Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand status took 14 milliseconds Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand stop took 4 milliseconds Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand clear Jul 18 23:48:24 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: 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} Jul 18 23:48:24 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: No code Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:24 volumio volumio[2226]: info: ------------------------------ 21ms Jul 18 23:48:24 volumio volumio[2226]: info: CoreCommandRouter::volumioGetQueue Jul 18 23:48:24 volumio volumio[2226]: info: CoreStateMachine::getQueue Jul 18 23:48:24 volumio volumio[2226]: info: CorePlayQueue::getQueue Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:24 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:24 volumio volumio[2226]: info: sendMpdCommand clear took 13 milliseconds Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.108:8200/MediaItems/791.wav" Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:24 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:24 volumio volumio[2226]: info: Jul 18 23:48:24 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:24 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:24 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:24 volumio volumio[2226]: info: ------------------------------ 4ms Jul 18 23:48:24 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.108:8200/MediaItems/791.wav" Jul 18 23:48:25 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:25 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:25 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 5ms Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 4ms Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand add "http://192.168.0.108:8200/MediaItems/791.wav" took 1 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand play Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:25 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:25 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand play took 2 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 1ms Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 3 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 8ms Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: info: Jul 18 23:48:25 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:25 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:25 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:25 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 26ms Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 26ms Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 25ms Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 23 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand status took 23 milliseconds Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 19 milliseconds Jul 18 23:48:25 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 19 milliseconds Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:25 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:25 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:25 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"791.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/791.wav","trackType":"wav"} Jul 18 23:48:25 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:25 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:25 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 59ms Jul 18 23:48:25 volumio volumio[2226]: info: ------------------------------ 58ms Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioNext Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::next Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::next Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand next Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand next took 24 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 1 Jul 18 23:48:26 volumio volumio[2226]: 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} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 1 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::play index undefined Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: 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} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: No code Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::startPlaybackTimer Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: [1752853706665] ControllerUPNPBrowser::clearAddPlayTrack Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand stop Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 13ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 12ms Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 14 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand stop took 4 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand clear Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: 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} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService stop Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: No code Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 20ms Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand clear took 9 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.0.108:8200/MediaItems/786.wav" Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:26 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:26 volumio volumio[2226]: error: updateQueue error: null Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 9ms Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.108:8200/MediaItems/786.wav" Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 6ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 6ms Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand add "http://192.168.0.108:8200/MediaItems/786.wav" took 1 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand play Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces system playlist update Jul 18 23:48:26 volumio volumio[2226]: info: Ignoring MPD Status Update Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand play took 2 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 2ms Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 2 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 1 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: Jul 18 23:48:26 volumio volumio[2226]: ---------------------------- MPD announces state update: player Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::getState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand status Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 4 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 3 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus stop Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 18ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 22ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 22ms Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand status took 19 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 17 milliseconds Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 16 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseState Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 35ms Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 33ms Jul 18 23:48:26 volumio volumio[2226]: info: sendMpdCommand playlistinfo took 24 milliseconds Jul 18 23:48:26 volumio volumio[2226]: verbose: ControllerMpd::parseTrackInfo Jul 18 23:48:26 volumio volumio[2226]: info: ControllerMpd::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::servicePushState Jul 18 23:48:26 volumio volumio[2226]: info: CorePlayQueue::getTrack 2 Jul 18 23:48:26 volumio volumio[2226]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":6,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"786.wav","artist":null,"album":null,"uri":"http://192.168.0.108:8200/MediaItems/786.wav","trackType":"wav"} Jul 18 23:48:26 volumio volumio[2226]: verbose: CURRENT POSITION 2 Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState stateService play Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::syncState currentStatus play Jul 18 23:48:26 volumio volumio[2226]: info: Received an update from plugin. extracting info from payload Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreStateMachine::pushState Jul 18 23:48:26 volumio volumio[2226]: info: CoreCommandRouter::volumioPushState Jul 18 23:48:26 volumio volumio[2226]: info: ------------------------------ 51ms Jul 18 23:48:33 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:48:33 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:34 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:48:34 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:38 volumio volumio[2226]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jul 18 23:48:38 volumio volumio[2226]: info: Retrying Login Due to Network Error Jul 18 23:48:41 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:48:41 volumio volumio[2226]: info: Preload queue cleared Jul 18 23:48:41 volumio volumio[2226]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 23:48:41 volumio volumio[2226]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 23:48:41 volumio volumio[2226]: TypeError: Cannot read property 'length' of undefined Jul 18 23:48:41 volumio volumio[2226]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 18 23:48:41 volumio volumio[2226]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 18 23:48:41 volumio volumio[2226]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 18 23:48:41 volumio volumio[2226]: at Parser.emit (events.js:315:20) Jul 18 23:48:41 volumio volumio[2226]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 18 23:48:41 volumio volumio[2226]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 18 23:48:41 volumio volumio[2226]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 18 23:48:41 volumio volumio[2226]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 18 23:48:41 volumio volumio[2226]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 18 23:48:41 volumio volumio[2226]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 18 23:48:41 volumio volumio[2226]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 18 23:48:41 volumio volumio[2226]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 18 23:48:41 volumio volumio[2226]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 18 23:48:41 volumio volumio[2226]: at IncomingMessage.emit (events.js:327:22) Jul 18 23:48:41 volumio volumio[2226]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 23:48:41 volumio volumio[2226]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 23:48:41 volumio volumio[2226]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 23:48:42 volumio sudo[3809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 23:47 Jul 18 23:48:42 volumio sudo[3809]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"