-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Thu 2025-05-15 00:27:58 CST. -- May 15 00:26:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:03 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:03 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:03 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:08 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:08 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:08 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:13 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:13 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:13 volumio sudo[2346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 00:26:13 volumio sudo[2346]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:13 volumio sudo[2346]: pam_unix(sudo:session): session closed for user root May 15 00:26:13 volumio sudo[2348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 00:26:13 volumio sudo[2348]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:13 volumio sudo[2348]: pam_unix(sudo:session): session closed for user root May 15 00:26:14 volumio volumio[904]: verbose: New Socket.io Connection to 192.168.31.172 from 192.168.31.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::volumioGetVisibleSources May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:14 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 00:26:14 volumio volumio[904]: info: Received Get System Info May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:14 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:14 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:14 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:14 volumio volumio[904]: info: Listing playlists May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 15 00:26:14 volumio sudo[2354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 00:26:14 volumio sudo[2354]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:14 volumio sudo[2354]: pam_unix(sudo:session): session closed for user root May 15 00:26:14 volumio sudo[2356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 00:26:14 volumio sudo[2356]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:14 volumio sudo[2356]: pam_unix(sudo:session): session closed for user root May 15 00:26:14 volumio volumio[904]: verbose: New Socket.io Connection to 192.168.31.172 from 192.168.31.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 May 15 00:26:14 volumio volumio[904]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/*/6f8b1c94-b770-42c2-8692-d9d4b59e817d.jpg' May 15 00:26:14 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::volumioGetVisibleSources May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:15 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::volumioGetQueue May 15 00:26:15 volumio volumio[904]: info: CoreStateMachine::getQueue May 15 00:26:15 volumio volumio[904]: info: CorePlayQueue::getQueue May 15 00:26:15 volumio volumio[904]: info: Listing playlists May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 00:26:15 volumio volumio[904]: info: Received Get System Info May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:15 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:15 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:15 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 00:26:15 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 15 00:26:16 volumio volumio[904]: info: Received Get System Info May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:16 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:16 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:16 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 15 00:26:16 volumio volumio[904]: info: CURURI: albums://*/ May 15 00:26:16 volumio volumio[904]: info: Preload queue cleared May 15 00:26:18 volumio volumio[904]: info: Preload queue cleared May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::ClearQueue May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::serviceStop May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::serviceStop May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::stop May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::clearPlayQueue May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:26:18 volumio volumio[904]: info: Preload queue cleared May 15 00:26:18 volumio volumio[904]: info: Adding Item to queue: albums://*/ May 15 00:26:18 volumio volumio[904]: info: Exploding uri albums://*/ in service mpd May 15 00:26:18 volumio volumio[904]: error: Explode URI Error: null May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:18 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPlay May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::play index 0 May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::play index undefined May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: May 15 00:26:18 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand stop took 16 milliseconds May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:18 volumio volumio[904]: info: May 15 00:26:18 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:18 volumio volumio[904]: info: May 15 00:26:18 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand status took 1 milliseconds May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 00:26:18 volumio volumio[904]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:18 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: 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":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:18 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: No code May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: 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":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:18 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: No code May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: 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":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:18 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: No code May 15 00:26:18 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:18 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:18 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:18 volumio volumio[904]: info: ------------------------------ 52ms May 15 00:26:18 volumio volumio[904]: info: ------------------------------ 52ms May 15 00:26:18 volumio volumio[904]: info: ------------------------------ 51ms May 15 00:26:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:23 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:23 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:23 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:24 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 00:26:26 volumio volumio[904]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 15 00:26:26 volumio volumio[904]: info: Retrying Login Due to Network Error May 15 00:26:36 volumio volumio[904]: info: MyVolumio login type: Token May 15 00:26:37 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:37 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:38 volumio sudo[2445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 00:26:38 volumio sudo[2445]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:38 volumio sudo[2445]: pam_unix(sudo:session): session closed for user root May 15 00:26:38 volumio sudo[2447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 00:26:38 volumio sudo[2447]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:38 volumio sudo[2447]: pam_unix(sudo:session): session closed for user root May 15 00:26:38 volumio volumio[904]: verbose: New Socket.io Connection to 192.168.31.172 from 192.168.31.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetVisibleSources May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:38 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 00:26:38 volumio volumio[904]: info: Received Get System Info May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:38 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:38 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:38 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:38 volumio volumio[904]: info: Listing playlists May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:38 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:38 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 00:26:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 15 00:26:39 volumio sudo[2451]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 00:26:39 volumio sudo[2451]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:39 volumio sudo[2451]: pam_unix(sudo:session): session closed for user root May 15 00:26:39 volumio sudo[2454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 00:26:39 volumio sudo[2454]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 00:26:39 volumio sudo[2454]: pam_unix(sudo:session): session closed for user root May 15 00:26:39 volumio volumio[904]: verbose: New Socket.io Connection to 192.168.31.172 from 192.168.31.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_2_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::volumioGetVisibleSources May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:39 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::volumioGetQueue May 15 00:26:39 volumio volumio[904]: info: CoreStateMachine::getQueue May 15 00:26:39 volumio volumio[904]: info: CorePlayQueue::getQueue May 15 00:26:39 volumio volumio[904]: info: Listing playlists May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 00:26:39 volumio volumio[904]: info: Received Get System Info May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:39 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:39 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:39 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 00:26:39 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 15 00:26:40 volumio volumio[904]: info: Received Get System Info May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:40 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:40 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:40 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:42 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 15 00:26:42 volumio volumio[904]: info: CURURI: music-library May 15 00:26:42 volumio volumio[904]: info: Preload queue cleared May 15 00:26:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:26:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:26:43 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:26:43 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:26:43 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:26:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:26:43 volumio ntpd[814]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 15 00:26:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 15 00:26:43 volumio volumio[904]: info: CURURI: music-library/USB May 15 00:26:44 volumio volumio[904]: info: Preload queue cleared May 15 00:26:45 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 15 00:26:45 volumio volumio[904]: info: CURURI: music-library/USB/D8C1C18581164309 May 15 00:26:45 volumio volumio[904]: info: Preload queue cleared May 15 00:26:49 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 00:26:49 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 15 00:26:49 volumio volumio[904]: info: CURURI: music-library/USB/D8C1C18581164309/PCM-DSD May 15 00:26:49 volumio volumio[904]: info: Preload queue cleared May 15 00:26:53 volumio volumio[904]: info: Preload queue cleared May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::ClearQueue May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::clearPlayQueue May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:26:53 volumio volumio[904]: info: Preload queue cleared May 15 00:26:53 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:26:53 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:26:53 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:26:53 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPlay May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::play index 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:26:53 volumio volumio[904]: info: Preload queue cleared May 15 00:26:53 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:26:53 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::play index undefined May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::startPlaybackTimer May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::clearAddPlayTracks USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand stop took 2 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand clear May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand clear took 1 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/192K.flac" May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: error: updateQueue error: null May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 4ms May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/192K.flac" took 3 milliseconds May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand play May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:53 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 6ms May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand play took 6 milliseconds May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 5ms May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 4ms May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121 May 15 00:26:53 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand status took 5 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand status took 8 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand status took 6 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio volumio[904]: info: May 15 00:26:53 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand status took 5 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:53 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:53 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5 Kbps","isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:53 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 37ms May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 59ms May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 56ms May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 56ms May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand status took 47 milliseconds May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 42 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5 Kbps","isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:53 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 64ms May 15 00:26:53 volumio volumio[904]: info: sendMpdCommand playlistinfo took 19 milliseconds May 15 00:26:53 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:53 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":505,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5 Kbps","isStreaming":false,"title":"Sonata No. 60 in C major, Hob. XVI/50: I. Allegro","artist":"Gottlieb Wallisch","album":"Haydn: The London Sonatas","uri":"USB/D8C1C18581164309/PCM-DSD/192K.flac","trackType":"flac"} May 15 00:26:53 volumio volumio[904]: verbose: CURRENT POSITION 1 May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:53 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:53 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:53 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:53 volumio volumio[904]: info: ------------------------------ 82ms May 15 00:26:54 volumio volumio[904]: info: Preload queue cleared May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::ClearQueue May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::serviceStop May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::serviceStop May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::stop May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::clearPlayQueue May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:26:54 volumio volumio[904]: info: Preload queue cleared May 15 00:26:54 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:26:54 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:26:54 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:26:54 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:26:54 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:26:54 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:26:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPlay May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::play index 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::play index undefined May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::startPlaybackTimer May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::clearAddPlayTracks USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand stop took 21 milliseconds May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand stop took 3 milliseconds May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand clear May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 5 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand clear took 4 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 3 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 3 milliseconds May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/176.4K.flac" May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: No code May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: No code May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 34ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 34ms May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio volumio[904]: error: updateQueue error: null May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 41ms May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 39 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/176.4K.flac" took 39 milliseconds May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 10ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 9ms May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand play May 15 00:26:54 volumio volumio[904]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 48ms May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:26:54 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:26:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121 May 15 00:26:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 19ms May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand play took 17 milliseconds May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 17ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 16ms May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 34 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 33 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 33 milliseconds May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: May 15 00:26:54 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::getState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 7 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 6 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 5 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand status took 4 milliseconds May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:54 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:54 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 60ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 73ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 72ms May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 35 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 35 milliseconds May 15 00:26:54 volumio volumio[904]: info: sendMpdCommand playlistinfo took 35 milliseconds May 15 00:26:54 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":740,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5301 Kbps","isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:54 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":740,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5301 Kbps","isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:54 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":740,"duration":216,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5301 Kbps","isStreaming":false,"title":"Spanish Harlem","artist":"Rebecca Pidgeon","album":"The Raven","uri":"USB/D8C1C18581164309/PCM-DSD/176.4K.flac","trackType":"flac"} May 15 00:26:54 volumio volumio[904]: verbose: CURRENT POSITION 2 May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:26:54 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:26:54 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:26:54 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 84ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 82ms May 15 00:26:54 volumio volumio[904]: info: ------------------------------ 81ms May 15 00:27:00 volumio volumio[904]: info: Preload queue cleared May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::ClearQueue May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::serviceStop May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 2 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::serviceStop May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::stop May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::clearPlayQueue May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:27:00 volumio volumio[904]: info: Preload queue cleared May 15 00:27:00 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:27:00 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPlay May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::play index 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::addQueueItems May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::addQueueItems May 15 00:27:00 volumio volumio[904]: info: Preload queue cleared May 15 00:27:00 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:27:00 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/192K.flac May 15 00:27:00 volumio volumio[904]: info: Adding Item to queue: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:27:00 volumio volumio[904]: info: Using cached record of: music-library/USB/D8C1C18581164309/PCM-DSD/176.4K.flac May 15 00:27:00 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushQueue May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::saveQueue May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::play index undefined May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::updateTrackBlock May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrackBlock May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::startPlaybackTimer May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::clearAddPlayTracks USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand stop May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand stop took 20 milliseconds May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand stop took 3 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand clear May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 3 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand clear took 3 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 1 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav" May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: No code May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: No code May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 31ms May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 31ms May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio volumio[904]: error: updateQueue error: null May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 34ms May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 32 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav" took 32 milliseconds May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand play May 15 00:27:00 volumio volumio[904]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 38ms May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:00 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:00 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121 May 15 00:27:00 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 13ms May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand play took 12 milliseconds May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 11ms May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 11ms May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 6 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 6 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 8 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 7 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":394,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus stop May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":397,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:00 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 22ms May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 26ms May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: May 15 00:27:00 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 21 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 22 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 3 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":411,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:00 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":431,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:00 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 52ms May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 51ms May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 27 milliseconds May 15 00:27:00 volumio volumio[904]: info: sendMpdCommand playlistinfo took 27 milliseconds May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":737,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:00 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":737,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:00 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:00 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:00 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:00 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 52ms May 15 00:27:00 volumio volumio[904]: info: ------------------------------ 51ms May 15 00:27:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:27:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:27:03 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:27:03 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:27:03 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:03 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:27:06 volumio volumio[904]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 15 00:27:06 volumio volumio[904]: info: Retrying Login Due to Network Error May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 1 May 15 00:27:07 volumio volumio[904]: info: Prefetching next song May 15 00:27:07 volumio volumio[904]: info: DOING PREFETCH IN MPD May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/192K.flac" May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:07 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand add "USB/D8C1C18581164309/PCM-DSD/192K.flac" took 1 milliseconds May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand consume 1 May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:07 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces system playlist update May 15 00:27:07 volumio volumio[904]: info: Ignoring MPD Status Update May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces state update: options May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand consume 1 took 3 milliseconds May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 3ms May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 2ms May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces state update: options May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:07 volumio volumio[904]: info: May 15 00:27:07 volumio volumio[904]: ---------------------------- MPD announces state update: options May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand status took 1 milliseconds May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 00:27:07 volumio volumio[904]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 00:27:07 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7147,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:07 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:07 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7147,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:07 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:07 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7147,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:07 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState stateService play May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus play May 15 00:27:07 volumio volumio[904]: info: Received an update from plugin. extracting info from payload May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:07 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:07 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 39ms May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 39ms May 15 00:27:07 volumio volumio[904]: info: ------------------------------ 38ms May 15 00:27:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:27:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:27:08 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:27:08 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:27:08 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:08 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::volumioPause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::servicePause May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::servicePause May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::pause May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand pause May 15 00:27:09 volumio volumio[904]: info: May 15 00:27:09 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand pause took 1 milliseconds May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:09 volumio volumio[904]: info: May 15 00:27:09 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:09 volumio volumio[904]: info: May 15 00:27:09 volumio volumio[904]: ---------------------------- MPD announces state update: player May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::getState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand status May 15 00:27:09 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand status took 2 milliseconds May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand status took 1 milliseconds May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseState May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 00:27:09 volumio volumio[904]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:09 volumio volumio[904]: verbose: ControllerMpd::parseTrackInfo May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9097,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:09 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState stateService pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9097,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:09 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState stateService pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:27:09 volumio volumio[904]: info: ControllerMpd::pushState May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::servicePushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9097,"duration":12,"samplerate":"352.8 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16_352k_PerfectTest.wav","artist":null,"album":null,"uri":"USB/D8C1C18581164309/PCM-DSD/16_352k_PerfectTest.wav","trackType":"wav"} May 15 00:27:09 volumio volumio[904]: verbose: CURRENT POSITION 0 May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState stateService pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::syncState currentStatus pause May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::pushState May 15 00:27:09 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:09 volumio volumio[904]: info: CoreCommandRouter::volumioPushState May 15 00:27:09 volumio volumio[904]: info: CoreStateMachine::stPlaybackTimer May 15 00:27:09 volumio volumio[904]: info: ------------------------------ 24ms May 15 00:27:09 volumio volumio[904]: info: ------------------------------ 24ms May 15 00:27:09 volumio volumio[904]: info: ------------------------------ 24ms May 15 00:27:16 volumio volumio[904]: info: MyVolumio login type: Token May 15 00:27:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:27:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:27:23 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:27:23 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:27:23 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:23 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:27:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:27:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:27:38 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:27:38 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:27:38 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:38 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:27:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 00:27:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 00:27:43 volumio volumio[904]: info: Discovery: Getting this device information May 15 00:27:43 volumio volumio[904]: info: CoreCommandRouter::volumioGetState May 15 00:27:43 volumio volumio[904]: info: CorePlayQueue::getTrack 0 May 15 00:27:43 volumio volumio[904]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 00:27:46 volumio volumio[904]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 15 00:27:46 volumio volumio[904]: info: Retrying Login Due to Network Error May 15 00:27:56 volumio volumio[904]: info: MyVolumio login type: Token May 15 00:27:58 volumio volumio[904]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 00:27:58 volumio volumio[904]: Error: connect ETIMEDOUT 128.121.243.106:80 May 15 00:27:58 volumio volumio[904]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 15 00:27:58 volumio volumio[904]: errno: -110, May 15 00:27:58 volumio volumio[904]: code: 'ETIMEDOUT', May 15 00:27:58 volumio volumio[904]: syscall: 'connect', May 15 00:27:58 volumio volumio[904]: address: '128.121.243.106', May 15 00:27:58 volumio volumio[904]: port: 80 May 15 00:27:58 volumio volumio[904]: } May 15 00:27:58 volumio volumio[904]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 00:27:58 volumio sudo[2678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-15 00:26 May 15 00:27:58 volumio sudo[2678]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"