-- Logs begin at Fri 2025-09-12 19:14:12 WIB, end at Fri 2025-09-12 19:19:56 WIB. -- Sep 12 19:18:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:01 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:01 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:01 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:04 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:04 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:04 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:08 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27 from 192.168.88.145 UA: Mozilla/5.0 (Linux; Android 14; ASUS_AI2201_D Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.160 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Sep 12 19:18:08 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:08 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:08 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:08 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:08 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:08 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:09 rivo volumio[3177]: info: Received Get System Info Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:09 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetVisibleSources Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetQueue Sep 12 19:18:09 rivo volumio[3177]: info: CoreStateMachine::getQueue Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getQueue Sep 12 19:18:09 rivo volumio[3177]: info: Listing playlists Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 12 19:18:09 rivo volumio[3177]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 12 19:18:09 rivo volumio[3177]: info: Received Get System Info Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:09 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:09 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:09 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:09 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:09 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:09 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:14 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:14 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:14 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:19 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:19 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:19 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:21 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 12 19:18:21 rivo volumio[3177]: info: CURURI: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1 Sep 12 19:18:21 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:21 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav in service mpd Sep 12 19:18:21 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F01%20Beat%20Hotel.wav&metadata=false Sep 12 19:18:21 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav in service mpd Sep 12 19:18:21 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F02%20Wheel%20of%20Fortune.wav&metadata=false Sep 12 19:18:21 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav in service mpd Sep 12 19:18:21 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F03%20Turned%20My%20Upside%20Down.wav&metadata=false Sep 12 19:18:21 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav in service mpd Sep 12 19:18:21 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F04%20The%20Painter.wav&metadata=false Sep 12 19:18:21 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav in service mpd Sep 12 19:18:21 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F05%20Stop%20Those%20Bells.wav&metadata=false Sep 12 19:18:21 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:21 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F06%20Set%20'em%20Up%2C%20Joe.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F07%20No%20Sanctuary%20Here.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F08%20Not%20a%20Matter%20of%20Pride.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F09%20Angel%20in%20Deep%20Shadow.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F10%20Mr.%20Bones.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F11%20Argyle%20Bridge.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F12%20Words%20of%20Love.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F13%20Save%20The%20Whales....wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F14%20Captain%20of%20the%20Loving%20Kind.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F15%20Moon%20In%20The%20Glass.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F16%20Pearl%20Diver.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:22 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav in service mpd Sep 12 19:18:22 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FCloser%20to%20the%20Music%20-%20Volume%201%2F17%20Before%20I%20Die.wav&metadata=false Sep 12 19:18:22 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:22 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::ClearQueue Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::stPlaybackTimer Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::serviceStop Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::serviceStop Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::stop Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::clearPlayQueue Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:18:22 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:22 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Sep 12 19:18:22 rivo kernel: spdif_a keep clk continuous Sep 12 19:18:22 rivo kernel: aml_spdif_close Sep 12 19:18:22 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPlay Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::play index 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:18:22 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:22 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:22 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::play index undefined Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::startPlaybackTimer Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:18:22 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand stop took 124 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand stop took 25 milliseconds Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand clear Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand status took 16 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand clear took 13 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand status took 11 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand status took 10 milliseconds Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav" Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: 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} Sep 12 19:18:22 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: No code Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: 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} Sep 12 19:18:22 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: No code Sep 12 19:18:22 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:22 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:22 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:22 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 122ms Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 124ms Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo volumio[3177]: error: updateQueue error: null Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 145ms Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 141 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: sendMpdCommand add "INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav" took 141 milliseconds Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 27ms Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 24ms Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:22 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand play Sep 12 19:18:22 rivo volumio[3177]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 12 19:18:22 rivo volumio[3177]: info: ------------------------------ 170ms Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo volumio[3177]: info: Sep 12 19:18:22 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:22 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:22 rivo kernel: aml_spdif_open Sep 12 19:18:22 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Sep 12 19:18:22 rivo kernel: set normal 512 fs /4 fs Sep 12 19:18:22 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:18:22 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:18:22 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Sep 12 19:18:22 rivo kernel: set normal 512 fs /4 fs Sep 12 19:18:22 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:18:22 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:18:22 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:18:22 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:18:22 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:18:22 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:18:22 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 89ms Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand play took 84 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 80ms Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 77ms Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: MCU Signalled Playback Inactive Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 35 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 33 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 32 milliseconds Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: Sep 12 19:18:23 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:23 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:23 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 50 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 47 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 52 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 48 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand status took 47 milliseconds Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:23 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:23 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 163ms Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 201ms Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 199ms Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 114 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 110 milliseconds Sep 12 19:18:23 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 110 milliseconds Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:23 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:23 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:23 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":416,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 Beat Hotel.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav","trackType":"wav"} Sep 12 19:18:23 rivo volumio[3177]: verbose: CURRENT POSITION 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:23 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:23 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:23 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:23 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 291ms Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 283ms Sep 12 19:18:23 rivo volumio[3177]: info: ------------------------------ 281ms Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:23 rivo volumio[3177]: info: MCU Signalled Playback Active Sep 12 19:18:23 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Sep 12 19:18:23 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Sep 12 19:18:24 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:24 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:24 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:28 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::ClearQueue Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::stPlaybackTimer Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::serviceStop Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 0 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::serviceStop Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::stop Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::clearPlayQueue Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:18:28 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/01 Beat Hotel.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/02 Wheel of Fortune.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/03 Turned My Upside Down.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/04 The Painter.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/05 Stop Those Bells.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/06 Set 'em Up, Joe.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:28 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Sep 12 19:18:28 rivo kernel: spdif_a keep clk continuous Sep 12 19:18:28 rivo kernel: aml_spdif_close Sep 12 19:18:28 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPlay Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::play index 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:18:28 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/08 Not a Matter of Pride.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/09 Angel in Deep Shadow.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/10 Mr. Bones.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/11 Argyle Bridge.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/12 Words of Love.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/13 Save The Whales....wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/14 Captain of the Loving Kind.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/15 Moon In The Glass.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/16 Pearl Diver.wav Sep 12 19:18:28 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:28 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Closer to the Music - Volume 1/17 Before I Die.wav Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::play index undefined Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::startPlaybackTimer Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand stop took 90 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand stop took 22 milliseconds Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand clear Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 15 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand clear took 14 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 9 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 8 milliseconds Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav" Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: 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} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: No code Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: 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} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: No code Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 115ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 114ms Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo volumio[3177]: error: updateQueue error: null Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 134ms Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 132 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand add "INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav" took 133 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 26ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 25ms Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand play Sep 12 19:18:28 rivo volumio[3177]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 157ms Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:18:28 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:18:28 rivo kernel: aml_spdif_open Sep 12 19:18:28 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Sep 12 19:18:28 rivo kernel: set normal 512 fs /4 fs Sep 12 19:18:28 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:18:28 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:18:28 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Sep 12 19:18:28 rivo kernel: set normal 512 fs /4 fs Sep 12 19:18:28 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:18:28 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:18:28 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:18:28 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:18:28 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:18:28 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 81ms Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand play took 73 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 71ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 70ms Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 20 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 18 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 17 milliseconds Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: Sep 12 19:18:28 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:18:28 rivo volumio[3177]: info: MCU Signalled Playback Inactive Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 14 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 10 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand status took 8 milliseconds Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:28 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:28 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 75ms Sep 12 19:18:28 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 108ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 108ms Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 84 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 83 milliseconds Sep 12 19:18:28 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 84 milliseconds Sep 12 19:18:28 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:28 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:28 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 No Sanctuary Here.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Closer to the Music - Volume 1/07 No Sanctuary Here.wav","trackType":"wav"} Sep 12 19:18:28 rivo volumio[3177]: verbose: CURRENT POSITION 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:18:28 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:18:28 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:28 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:18:28 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 242ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 236ms Sep 12 19:18:28 rivo volumio[3177]: info: ------------------------------ 239ms Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:18:28 rivo volumio[3177]: info: MCU Signalled Playback Active Sep 12 19:18:29 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:29 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:29 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:31 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:31 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:31 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:34 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:34 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:34 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:39 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:39 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:39 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:44 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:44 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:44 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:45 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27 from 192.168.88.145 UA: Mozilla/5.0 (Linux; Android 14; ASUS_AI2201_D Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.160 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Sep 12 19:18:45 rivo volumio[3177]: info: Received Get System Info Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:45 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetVisibleSources Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetQueue Sep 12 19:18:45 rivo volumio[3177]: info: CoreStateMachine::getQueue Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getQueue Sep 12 19:18:45 rivo volumio[3177]: info: Listing playlists Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 12 19:18:45 rivo volumio[3177]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 12 19:18:45 rivo volumio[3177]: info: Received Get System Info Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:45 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:45 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:45 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:49 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:49 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:49 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:53 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:18:53 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:18:53 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:18:53 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:18:53 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:18:53 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:18:54 rivo ntpd[3546]: Soliciting pool server 27.54.117.72 Sep 12 19:18:54 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:54 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:54 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:18:54 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Sep 12 19:18:54 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Sep 12 19:18:58 rivo ntpd[3546]: Soliciting pool server 202.162.32.12 Sep 12 19:18:58 rivo ntpd[3546]: Soliciting pool server 202.162.32.12 Sep 12 19:18:59 rivo ntpd[3546]: Soliciting pool server 103.28.56.14 Sep 12 19:18:59 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:18:59 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:18:59 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:19:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:19:01 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:19:01 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:01 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:01 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:19:04 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:04 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:04 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:09 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:09 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:09 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:14 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:14 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:14 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:19 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:19 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:19 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:24 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:24 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:24 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:24 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:19:24 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:19:24 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:19:24 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:24 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:24 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:19:29 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:29 rivo volumio-time-update[2830]: volumio-time-update-util: Date not found in response Sep 12 19:19:29 rivo volumio-time-update[2830]: volumio-time-update-util: Retrying in 5 seconds... Sep 12 19:19:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 12 19:19:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 12 19:19:31 rivo volumio[3177]: info: Discovery: Getting this device information Sep 12 19:19:31 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:31 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:31 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 12 19:19:33 rivo dhcpcd[3467]: eth0: adding default route via 192.168.88.1 Sep 12 19:19:33 rivo ntpd[3546]: ntpd exiting on signal 15 (Terminated) Sep 12 19:19:33 rivo systemd[1]: Stopping Network Time Service... Sep 12 19:19:33 rivo systemd[1]: ntp.service: Succeeded. Sep 12 19:19:33 rivo systemd[1]: Stopped Network Time Service. Sep 12 19:19:33 rivo systemd[1]: Starting Network Time Service... Sep 12 19:19:33 rivo ntpd[5726]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 12 19:19:33 rivo ntpd[5726]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 12 19:19:33 rivo systemd[1]: Started Network Time Service. Sep 12 19:19:33 rivo ntpd[5742]: proto: precision = 1.250 usec (-20) Sep 12 19:19:33 rivo ntpd[5742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 12 19:19:33 rivo ntpd[5742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 12 19:19:33 rivo ntpd[5742]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 990 days ago Sep 12 19:19:33 rivo ntpd[5742]: Listen and drop on 0 v6wildcard [::]:123 Sep 12 19:19:33 rivo ntpd[5742]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 12 19:19:33 rivo ntpd[5742]: Listen normally on 2 lo 127.0.0.1:123 Sep 12 19:19:33 rivo ntpd[5742]: Listen normally on 3 eth0 192.168.88.27:123 Sep 12 19:19:33 rivo ntpd[5742]: Listen normally on 4 wlan0 192.168.211.1:123 Sep 12 19:19:33 rivo ntpd[5742]: Listen normally on 5 wlan0 169.254.222.157:123 Sep 12 19:19:33 rivo ntpd[5742]: Listening on routing socket on fd #22 for interface updates Sep 12 19:19:33 rivo ntpd[5742]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 12 19:19:33 rivo ntpd[5742]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 12 19:19:34 rivo ntpd[5742]: ntpd exiting on signal 15 (Terminated) Sep 12 19:19:34 rivo systemd[1]: Stopping Network Time Service... Sep 12 19:19:34 rivo systemd[1]: ntp.service: Succeeded. Sep 12 19:19:34 rivo systemd[1]: Stopped Network Time Service. Sep 12 19:19:34 rivo systemd[1]: Starting Network Time Service... Sep 12 19:19:34 rivo ntpd[5776]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 12 19:19:34 rivo ntpd[5776]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 12 19:19:34 rivo systemd[1]: Started Network Time Service. Sep 12 19:19:34 rivo ntpd[5782]: proto: precision = 1.250 usec (-20) Sep 12 19:19:34 rivo ntpd[5782]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 12 19:19:34 rivo ntpd[5782]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 12 19:19:34 rivo ntpd[5782]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 990 days ago Sep 12 19:19:34 rivo ntpd[5782]: Listen and drop on 0 v6wildcard [::]:123 Sep 12 19:19:34 rivo ntpd[5782]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 12 19:19:34 rivo ntpd[5782]: Listen normally on 2 lo 127.0.0.1:123 Sep 12 19:19:34 rivo ntpd[5782]: Listen normally on 3 eth0 192.168.88.27:123 Sep 12 19:19:34 rivo ntpd[5782]: Listen normally on 4 wlan0 192.168.211.1:123 Sep 12 19:19:34 rivo ntpd[5782]: Listen normally on 5 wlan0 169.254.222.157:123 Sep 12 19:19:34 rivo ntpd[5782]: Listening on routing socket on fd #22 for interface updates Sep 12 19:19:34 rivo ntpd[5782]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 12 19:19:34 rivo ntpd[5782]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 12 19:19:34 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 12 19:19:34 rivo volumio[3177]: info: CURURI: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me Sep 12 19:19:34 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/01 In A Sentimental Mood.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/02 Cry Me A River.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/03 Moon River.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/04 What A Wonderful World.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/05 Summertime.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sentimental Reasons.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sintimental Reason.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/08 Perhaps, Perhaps, Perhaps.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/09 My Funny Valentine.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/10 Smile.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/11 Beyond The Sea.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/12 Fly Me To The Moon.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/13 A Whiter Shade Of Pale.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/14 La Vie En Rose.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/15 The Girl From Ipanema.wav Sep 12 19:19:34 rivo volumio[3177]: info: Preloading song: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/16 Time To Say Goodbye.wav Sep 12 19:19:34 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/01 In A Sentimental Mood.wav in service mpd Sep 12 19:19:34 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F01%20In%20A%20Sentimental%20Mood.wav&metadata=false Sep 12 19:19:34 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/01 In A Sentimental Mood.wav Sep 12 19:19:34 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/02 Cry Me A River.wav in service mpd Sep 12 19:19:34 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F02%20Cry%20Me%20A%20River.wav&metadata=false Sep 12 19:19:34 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/02 Cry Me A River.wav Sep 12 19:19:34 rivo volumio-time-update[2830]: volumio-time-update-util: Fetching time from Volumio... Sep 12 19:19:34 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/03 Moon River.wav in service mpd Sep 12 19:19:34 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F03%20Moon%20River.wav&metadata=false Sep 12 19:19:34 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/03 Moon River.wav Sep 12 19:19:34 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/04 What A Wonderful World.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F04%20What%20A%20Wonderful%20World.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/04 What A Wonderful World.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/05 Summertime.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F05%20Summertime.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/05 Summertime.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sentimental Reasons.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F06%20I%20Love%20You%20For%20Sentimental%20Reasons.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sentimental Reasons.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sintimental Reason.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F06%20I%20Love%20You%20For%20Sintimental%20Reason.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sintimental Reason.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F07%20Autumn%20Leaves.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/08 Perhaps, Perhaps, Perhaps.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F08%20Perhaps%2C%20Perhaps%2C%20Perhaps.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/08 Perhaps, Perhaps, Perhaps.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/09 My Funny Valentine.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F09%20My%20Funny%20Valentine.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/09 My Funny Valentine.wav Sep 12 19:19:35 rivo ntpd[5782]: Soliciting pool server 185.125.190.58 Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/10 Smile.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F10%20Smile.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/10 Smile.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/11 Beyond The Sea.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F11%20Beyond%20The%20Sea.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/11 Beyond The Sea.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/12 Fly Me To The Moon.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F12%20Fly%20Me%20To%20The%20Moon.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/12 Fly Me To The Moon.wav Sep 12 19:19:35 rivo volumio-time-update[2830]: volumio-time-update-util: Setting system time to: 2025-09-12 19:19:46 Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/13 A Whiter Shade Of Pale.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F13%20A%20Whiter%20Shade%20Of%20Pale.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/13 A Whiter Shade Of Pale.wav Sep 12 19:19:35 rivo sudo[5794]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-09-12 19:19:46 Sep 12 19:19:35 rivo sudo[5794]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/14 La Vie En Rose.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F14%20La%20Vie%20En%20Rose.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/14 La Vie En Rose.wav Sep 12 19:19:35 rivo dbus-daemon[2837]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.20' (uid=0 pid=5795 comm="timedatectl set-time 2025-09-12 19:19:46 " label="kernel") Sep 12 19:19:35 rivo systemd[1]: Starting Time & Date Service... Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/15 The Girl From Ipanema.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F15%20The%20Girl%20From%20Ipanema.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/15 The Girl From Ipanema.wav Sep 12 19:19:35 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::ClearQueue Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::stPlaybackTimer Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::serviceStop Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 6 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::serviceStop Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::stop Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::clearPlayQueue Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:19:35 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/01 In A Sentimental Mood.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/01 In A Sentimental Mood.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/02 Cry Me A River.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/02 Cry Me A River.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/03 Moon River.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/03 Moon River.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/04 What A Wonderful World.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/04 What A Wonderful World.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/05 Summertime.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/05 Summertime.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sentimental Reasons.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sentimental Reasons.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sintimental Reason.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/06 I Love You For Sintimental Reason.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav Sep 12 19:19:35 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Sep 12 19:19:35 rivo kernel: spdif_a keep clk continuous Sep 12 19:19:35 rivo kernel: aml_spdif_close Sep 12 19:19:35 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPlay Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::play index 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::addQueueItems Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::addQueueItems Sep 12 19:19:35 rivo volumio[3177]: info: Preload queue cleared Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/08 Perhaps, Perhaps, Perhaps.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/08 Perhaps, Perhaps, Perhaps.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/09 My Funny Valentine.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/09 My Funny Valentine.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/10 Smile.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/10 Smile.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/11 Beyond The Sea.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/11 Beyond The Sea.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/12 Fly Me To The Moon.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/12 Fly Me To The Moon.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/13 A Whiter Shade Of Pale.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/13 A Whiter Shade Of Pale.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/14 La Vie En Rose.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/14 La Vie En Rose.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/15 The Girl From Ipanema.wav Sep 12 19:19:35 rivo volumio[3177]: info: Using cached record of: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/15 The Girl From Ipanema.wav Sep 12 19:19:35 rivo volumio[3177]: info: Adding Item to queue: music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/16 Time To Say Goodbye.wav Sep 12 19:19:35 rivo volumio[3177]: info: Exploding uri music-library/INTERNAL/Vocal/Halie Loren - Romance With Me/16 Time To Say Goodbye.wav in service mpd Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::play index undefined Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::startPlaybackTimer Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetVisibleSources Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 19:19:35 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:35 rivo volumio[3177]: info: ALBUMART /albumart?cacheid=552&web=//extralarge&path=%2Fmnt%2FINTERNAL%2FVocal%2FHalie%20Loren%20-%20Romance%20With%20Me%2F16%20Time%20To%20Say%20Goodbye.wav&metadata=false Sep 12 19:19:35 rivo volumio[3177]: info: URI /mnt/INTERNAL/Vocal/Halie Loren - Romance With Me/16 Time To Say Goodbye.wav Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand stop took 72 milliseconds Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand stop took 21 milliseconds Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand clear Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushQueue Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::saveQueue Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::updateTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrackBlock Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:35 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand status took 26 milliseconds Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand clear took 26 milliseconds Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand status took 10 milliseconds Sep 12 19:19:35 rivo volumio[3177]: info: sendMpdCommand status took 9 milliseconds Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav" Sep 12 19:19:35 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: 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} Sep 12 19:19:35 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: No code Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: 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} Sep 12 19:19:35 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::syncState stateService stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: No code Sep 12 19:19:35 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:35 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:35 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:35 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:35 rivo volumio[3177]: info: ------------------------------ 88ms Sep 12 19:19:35 rivo volumio[3177]: info: ------------------------------ 88ms Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:35 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:35 rivo volumio[3177]: info: Sep 12 19:19:35 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:35 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: error: updateQueue error: null Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:36 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 328ms Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 325 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand add "INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav" took 326 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 248ms Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 246ms Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand play Sep 12 19:19:36 rivo volumio[3177]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 364ms Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:36 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces system playlist update Sep 12 19:19:36 rivo volumio[3177]: info: Ignoring MPD Status Update Sep 12 19:19:36 rivo kernel: aml_spdif_open Sep 12 19:19:36 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Sep 12 19:19:36 rivo kernel: set normal 512 fs /4 fs Sep 12 19:19:36 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:19:36 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:19:36 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Sep 12 19:19:36 rivo kernel: set normal 512 fs /4 fs Sep 12 19:19:36 rivo kernel: set spdifout clk:5644800, mpll:22579200 Sep 12 19:19:36 rivo kernel: get spdifout clk:5644797, mpll:22579186 Sep 12 19:19:36 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:19:36 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:19:36 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Sep 12 19:19:36 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 44ms Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand play took 37 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 33ms Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 30ms Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo volumio[3177]: info: MCU Signalled Playback Inactive Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 110 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 110 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 102 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 97 milliseconds Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Sep 12 19:19:36 rivo volumio[3177]: info: Sep 12 19:19:36 rivo volumio[3177]: ---------------------------- MPD announces state update: player Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::getState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 54 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 53 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 53 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 52 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 49 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand status took 47 milliseconds Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseState Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:19:36 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:19:36 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo ntpd[5782]: Soliciting pool server 103.28.56.14 Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:19:36 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo ntpd[5782]: Soliciting pool server 202.162.32.12 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 227ms Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 258ms Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 254ms Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 250ms Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 98 milliseconds Sep 12 19:19:36 rivo volumio[3177]: info: sendMpdCommand playlistinfo took 98 milliseconds Sep 12 19:19:36 rivo volumio[3177]: verbose: ControllerMpd::parseTrackInfo Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:19:36 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: ControllerMpd::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::servicePushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1464,"duration":232,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"07 Autumn Leaves.wav","artist":null,"album":null,"uri":"INTERNAL/Vocal/Halie Loren - Romance With Me/07 Autumn Leaves.wav","trackType":"wav"} Sep 12 19:19:36 rivo volumio[3177]: verbose: CURRENT POSITION 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState stateService play Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::syncState currentStatus play Sep 12 19:19:36 rivo volumio[3177]: info: Received an update from plugin. extracting info from payload Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: CoreStateMachine::pushState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioPushState Sep 12 19:19:36 rivo volumio[3177]: info: CoreCommandRouter::volumioGetState Sep 12 19:19:36 rivo volumio[3177]: info: CorePlayQueue::getTrack 7 Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Sep 12 19:19:36 rivo volumio[3177]: info: MRS: Pushing multiroomSync output Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 249ms Sep 12 19:19:36 rivo volumio[3177]: info: ------------------------------ 248ms Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Signalling Playback active due to playback status change Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: Updating RAAT Signal Path Sep 12 19:19:36 rivo volumio[3177]: info: MCU Signalled Playback Active Sep 12 19:19:36 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Sep 12 19:19:36 rivo volumio[3177]: verbose: New Socket.io Connection to 192.168.88.27:3000 from 192.168.88.145 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Sep 12 19:19:37 rivo ntpd[5782]: Soliciting pool server 103.75.96.206 Sep 12 19:19:37 rivo ntpd[5782]: Soliciting pool server 103.105.56.11 Sep 12 19:19:37 rivo ntpd[5782]: Soliciting pool server 202.65.114.202 Sep 12 19:19:38 rivo ntpd[5782]: Soliciting pool server 203.114.74.17 Sep 12 19:19:38 rivo ntpd[5782]: Soliciting pool server 116.12.47.30 Sep 12 19:19:38 rivo ntpd[5782]: Soliciting pool server 103.169.192.229 Sep 12 19:19:39 rivo ntpd[5782]: Soliciting pool server 103.105.57.11 Sep 12 19:19:39 rivo ntpd[5782]: Soliciting pool server 172.232.235.123 Sep 12 19:19:39 rivo ntpd[5782]: Soliciting pool server 27.54.117.72 Sep 12 19:19:40 rivo ntpd[5782]: Soliciting pool server 116.12.46.30 Sep 12 19:19:40 rivo ntpd[5782]: Soliciting pool server 103.245.159.58 Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 12 19:19:40 rivo volumio[3177]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 12 19:19:41 rivo ntpd[5782]: Soliciting pool server 2001:df0:3140:fac1:b090:12:1980:c01 Sep 12 19:19:42 rivo volumio[3177]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 12 19:19:42 rivo volumio[3177]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 12 19:19:42 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 19:19:42 rivo volumio[3177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 19:19:42 rivo volumio[3177]: info: Starting MyVolumio Remote Streaming Endpoints Sep 12 19:19:42 rivo volumio[3177]: info: MyVolumio login type: Token Sep 12 19:19:42 rivo volumio[3177]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 12 19:19:42 rivo volumio[3177]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Sep 12 19:19:42 rivo volumio[3177]: error: MyVolumio Custom Token format not valid, refreshing it Sep 12 19:19:54 rivo volumio[3177]: info: MyVolumio login type: Token Sep 12 19:19:55 rivo volumio[3177]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 12 19:19:56 rivo volumio[3177]: info: MyVolumio token set successfully Sep 12 19:19:56 rivo volumio[3177]: info: MYVOLUMIO: Adding device Sep 12 19:19:56 rivo volumio[3177]: info: MYVOLUMIO: Evaluating Server Sep 12 19:19:56 rivo dbus-daemon[2837]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 12 19:19:56 rivo systemd[1]: Started Time & Date Service. Sep 12 19:19:46 rivo systemd-timedated[5796]: Changed local time to Fri Sep 12 19:19:46 2025 Sep 12 19:19:46 rivo sudo[5794]: pam_unix(sudo:session): session closed for user root Sep 12 19:19:46 rivo volumio-time-update[2830]: volumio-time-update-util: System time updated successfully. Sep 12 19:19:46 rivo systemd[1]: Started Volumio Time Update Utility. Sep 12 19:19:46 rivo systemd[1]: Reached target Multi-User System. Sep 12 19:19:46 rivo systemd[1]: Reached target Graphical Interface. Sep 12 19:19:46 rivo systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 12 19:19:46 rivo volumio[3177]: info: MyVolumio status changed Sep 12 19:19:46 rivo volumio[3177]: info: Streaming services startup Sep 12 19:19:46 rivo volumio[3177]: info: Starting Streaming Daemon Sep 12 19:19:46 rivo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 12 19:19:46 rivo systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 12 19:19:46 rivo systemd[1]: Startup finished in 12.971s (kernel) + 5min 33.761s (userspace) = 5min 46.732s. Sep 12 19:19:46 rivo volumio[3177]: info: Removing browser output: myVolumio user plan is not superstar Sep 12 19:19:46 rivo volumio[3177]: info: Removing audio output: Sep 12 19:19:46 rivo volumio[3177]: info: Stoppping Tunnel 1 Sep 12 19:19:46 rivo sudo[5875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 12 19:19:46 rivo sudo[5875]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 19:19:46 rivo volumio[3177]: error: Failed to ping endpoint eu7.myvolumio.org : unknown error Sep 12 19:19:46 rivo volumio[3177]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 19:19:46 rivo sudo[5877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 12 19:19:46 rivo sudo[5877]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 19:19:46 rivo volumio[3177]: Error: Unable to resolve or reject the same promise twice Sep 12 19:19:46 rivo volumio[3177]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Sep 12 19:19:46 rivo volumio[3177]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Sep 12 19:19:46 rivo volumio[3177]: at Socket.emit (events.js:400:28) Sep 12 19:19:46 rivo volumio[3177]: at addChunk (internal/streams/readable.js:293:12) Sep 12 19:19:46 rivo volumio[3177]: at readableAddChunk (internal/streams/readable.js:267:9) Sep 12 19:19:46 rivo volumio[3177]: at Socket.Readable.push (internal/streams/readable.js:206:10) Sep 12 19:19:46 rivo volumio[3177]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Sep 12 19:19:46 rivo volumio[3177]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 19:19:46 rivo sudo[5875]: pam_unix(sudo:session): session closed for user root Sep 12 19:19:46 rivo sudo[5877]: pam_unix(sudo:session): session closed for user root Sep 12 19:19:46 rivo sudo[5889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-12 19:18 Sep 12 19:19:46 rivo sudo[5889]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:43:09 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="fc7d09bc07ffd188bff4808d8f79c746"