Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 08:05:10 keith---office volumio[1207]: info: Discovery: Getting this device information Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 08:05:10 keith---office volumio[1207]: verbose: New Socket.io Connection to 10.0.0.177 from 10.0.0.117 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/154.0.0.0 Safari/537.36 Engine version: 3 Transport: websocket Total Clients: 8 Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetQueue Oct 12 08:05:10 keith---office volumio[1207]: info: CoreStateMachine::getQueue Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getQueue Oct 12 08:05:10 keith---office volumio[1207]: info: Received Get System Version Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 08:05:10 keith---office volumio[1207]: info: Received Get System Info Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 08:05:10 keith---office volumio[1207]: info: Discovery: Getting this device information Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 12 08:05:10 keith---office volumio[1207]: info: CALLMETHOD: miscellanea novaui getTheme [object Object] Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: novaui , getTheme Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 12 08:05:10 keith---office sudo[2595]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 12 08:05:10 keith---office sudo[2595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office sudo[2600]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 08:05:10 keith---office sudo[2600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office sudo[2600]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office sudo[2607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 08:05:10 keith---office sudo[2607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office sudo[2595]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office sudo[2612]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 08:05:10 keith---office sudo[2612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 12 08:05:10 keith---office sudo[2607]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:10 keith---office sudo[2612]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetQueue Oct 12 08:05:10 keith---office volumio[1207]: info: CoreStateMachine::getQueue Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getQueue Oct 12 08:05:10 keith---office volumio[1207]: info: Received Get System Version Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 08:05:10 keith---office volumio[1207]: info: Received Get System Info Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 08:05:10 keith---office volumio[1207]: info: Discovery: Getting this device information Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:10 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 08:05:10 keith---office sudo[2617]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 08:05:10 keith---office sudo[2617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office sudo[2622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 08:05:10 keith---office sudo[2622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 08:05:10 keith---office sudo[2617]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office sudo[2622]: pam_unix(sudo:session): session closed for user root Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 08:05:10 keith---office volumio[1207]: info: Executing endpoint metavolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 12 08:05:10 keith---office volumio[1207]: info: Executing endpoint metavolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 12 08:05:10 keith---office volumio[1207]: info: Executing endpoint metavolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 12 08:05:10 keith---office volumio[1207]: info: Executing endpoint metavolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 12 08:05:10 keith---office volumio[1207]: info: Executing endpoint metavolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 08:05:10 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 08:05:14 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 08:05:14 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 08:05:16 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 08:05:16 keith---office volumio[1207]: info: CURURI: music-library Oct 12 08:05:16 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:05:17 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 08:05:21 keith---office volumio[1207]: info: Received Get System Version Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 08:05:21 keith---office volumio[1207]: info: Received Get System Info Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 08:05:21 keith---office volumio[1207]: info: Discovery: Getting this device information Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:05:21 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 08:05:21 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: Retrieving Cloud Streaming UI Oct 12 08:05:23 keith---office volumio[1207]: info: Getting Tidal Cloud Configuration Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: Getting Qobuz Cloud Configuration Oct 12 08:05:23 keith---office volumio[1207]: info: Asking plugin for UI Config Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: Getting Spotify Cloud Configuration Oct 12 08:05:23 keith---office volumio[1207]: info: Asking plugin for UI Config Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: Saving Spotify Acccount Oct 12 08:05:23 keith---office volumio[1207]: info: Got it Oct 12 08:05:23 keith---office volumio[1207]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 12 08:05:23 keith---office volumio[1207]: info: Got it Oct 12 08:05:23 keith---office volumio[1207]: info: Got Tidal Cloud Configuration Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 12 08:05:23 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: networkfs , listUsbDrives Oct 12 08:05:23 keith---office volumio[1207]: info: Error : CoreCommandRouter::executeOnPlugin: No method [listUsbDrives] in plugin networkfs Oct 12 08:05:23 keith---office volumio[1207]: error: Error on listing USB devices Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand rescan Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: info: Oct 12 08:05:25 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand rescan took 13 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 9 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 2 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: info: Command Router : Notfying DB Updatetrue Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:05:25 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: No code Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: ------------------------------ 95ms Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: info: Oct 12 08:05:25 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: info: Oct 12 08:05:25 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 4 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 6 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 6 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: info: sendMpdCommand status took 6 milliseconds Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: info: Command Router : Notfying DB Updatetrue Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::Close All Modals sent Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: info: Command Router : Notfying DB Updatetrue Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::Close All Modals sent Oct 12 08:05:25 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:05:25 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: No code Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:05:25 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:25 keith---office volumio[1207]: info: No code Oct 12 08:05:25 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:05:25 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:05:25 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:05:25 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:05:26 keith---office volumio[1207]: info: ------------------------------ 79ms Oct 12 08:05:26 keith---office volumio[1207]: info: ------------------------------ 79ms Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:26 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:05:27 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:31 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:35 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:39 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:43 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:47 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:51 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:55 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:05:59 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:06:00 keith---office volumio[1207]: info: MPD Database updated - AlbumList cache refreshed Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: database Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: MPD Database updated - AlbumList cache refreshed Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: database Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: MPD Database updated - AlbumList cache refreshed Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: database Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: Oct 12 08:06:00 keith---office volumio[1207]: ---------------------------- MPD announces state update: update Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::getState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::sendMpdCommand status Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 203 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 202 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 203 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: Command Router : Notfying DB Updatefalse Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::Close All Modals sent Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 360ms Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 361ms Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 427 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 427 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 427 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: Command Router : Notfying DB Updatefalse Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::Close All Modals sent Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 499ms Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 499ms Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 608 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 606 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: info: sendMpdCommand status took 606 milliseconds Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: Command Router : Notfying DB Updatefalse Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::Close All Modals sent Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: verbose: ControllerMpd::parseState Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ControllerMpd::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::servicePushState Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 08:06:00 keith---office volumio[1207]: verbose: CURRENT POSITION 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState stateService stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::syncState currentStatus stop Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: No code Oct 12 08:06:00 keith---office volumio[1207]: info: CoreStateMachine::pushState Oct 12 08:06:00 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:00 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushState Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output update for this device Oct 12 08:06:00 keith---office volumio[1207]: info: MRS: Pushing multiroomSync output Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 667ms Oct 12 08:06:00 keith---office volumio[1207]: info: ------------------------------ 668ms Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:00 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:01 keith---office volumio[1207]: info: Updating RAAT Signal Path Oct 12 08:06:03 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 08:06:04 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 08:06:04 keith---office volumio[1207]: info: CURURI: music-library Oct 12 08:06:04 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:06:05 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 08:06:05 keith---office volumio[1207]: info: CURURI: music-library/USB Oct 12 08:06:05 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:06:06 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 08:06:06 keith---office volumio[1207]: info: CURURI: music-library/USB/SAMPLES_KL1 Oct 12 08:06:06 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:06:14 keith---office volumio[1207]: info: CoreCommandRouter::volumioGetState Oct 12 08:06:14 keith---office volumio[1207]: info: CorePlayQueue::getTrack 0 Oct 12 08:06:17 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 08:06:17 keith---office volumio[1207]: info: CURURI: music-library/USB/SAMPLES_KL1/ZZ_Ward Oct 12 08:06:17 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:06:17 keith---office volumio[1207]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 08:06:19 keith---office volumio[1207]: info: Listing playlists Oct 12 08:06:21 keith---office volumio[1207]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 08:06:21 keith---office volumio[1207]: info: CoreStateMachine::ClearQueue Oct 12 08:06:21 keith---office volumio[1207]: info: CoreStateMachine::stop Oct 12 08:06:21 keith---office volumio[1207]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 08:06:21 keith---office volumio[1207]: info: CorePlayQueue::clearPlayQueue Oct 12 08:06:21 keith---office volumio[1207]: info: CorePlayQueue::saveQueue Oct 12 08:06:21 keith---office volumio[1207]: info: CoreCommandRouter::volumioPushQueue Oct 12 08:06:21 keith---office volumio[1207]: info: CoreStateMachine::addQueueItems Oct 12 08:06:21 keith---office volumio[1207]: info: CorePlayQueue::addQueueItems Oct 12 08:06:21 keith---office volumio[1207]: info: Preload queue cleared Oct 12 08:06:21 keith---office volumio[1207]: info: Adding Item to queue: music-library/USB/SAMPLES_KL1/ZZ_Ward/Til the Casket Drops Oct 12 08:06:21 keith---office volumio[1207]: info: Exploding uri music-library/USB/SAMPLES_KL1/ZZ_Ward/Til the Casket Drops in service mpd Oct 12 08:06:21 keith---office volumio[1207]: info: ALBUMART /albumart?cacheid=169&web=ZZ%20Ward/Til%20The%20Casket%20Drops/extralarge&path=%2Fmnt%2FUSB%2FSAMPLES_KL1%2FZZ_Ward%2FTil%20the%20Casket%20Drops%2F00-zz_ward-til_the_casket_drops-cd-flac-2012.cue&metadata=false Oct 12 08:06:21 keith---office volumio[1207]: info: URI /mnt/USB/SAMPLES_KL1/ZZ_Ward/Til the Casket Drops/00-zz_ward-til_the_casket_drops-cd-flac-2012.cue Oct 12 08:06:21 keith---office volumio[1207]: info: ALBUMART /albumart?cacheid=169&web=ZZ%20Ward/Til%20The%20Casket%20Drops/extralarge&path=%2Fmnt%2FUSB%2FSAMPLES_KL1%2FZZ_Ward%2FTil%20the%20Casket%20Drops%2F00-zz_ward-til_the_casket_drops-cd-flac-2012.cue&metadata=false Oct 12 08:06:21 keith---office volumio[1207]: info: URI /mnt/USB/SAMPLES_KL1/ZZ_Ward/Til the Casket Drops/00-zz_ward-til_the_casket_drops-cd-flac-2012.cue Oct 12 08:06:21 keith---office volumio[1207]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 08:06:21 keith---office volumio[1207]: Error: Unable to resolve or reject the same promise twice Oct 12 08:06:21 keith---office volumio[1207]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 12 08:06:21 keith---office volumio[1207]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Oct 12 08:06:21 keith---office volumio[1207]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Oct 12 08:06:21 keith---office volumio[1207]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Oct 12 08:06:21 keith---office volumio[1207]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Oct 12 08:06:21 keith---office volumio[1207]: at Socket.emit (node:events:514:28) Oct 12 08:06:21 keith---office volumio[1207]: at addChunk (node:internal/streams/readable:343:12) Oct 12 08:06:21 keith---office volumio[1207]: at readableAddChunk (node:internal/streams/readable:312:11) Oct 12 08:06:21 keith---office volumio[1207]: at Readable.push (node:internal/streams/readable:253:10) Oct 12 08:06:21 keith---office volumio[1207]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Oct 12 08:06:21 keith---office volumio[1207]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 08:06:21 keith---office sudo[2927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 08:05' Oct 12 08:06:21 keith---office sudo[2927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="e4cc75aeb55d8e9f68ae0a0f0d560517e2d633d6" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="emotivadrs1" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Sep 26 16:17:17 UTC 2026" VOLUMIO_VERSION="4.215" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Emotiva DRS-1" VOLUMIO_VENDOR="Emotiva" VOLUMIO_MODEL="DRS-1" VOLUMIO_HASH="84f808eeba24182351653412ddbbbf35"