Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::volumioGetBrowseSources Mar 26 04:25:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 04:25:06 room volumio[1288]: error: MyVolumio Plugin failed to authenticate in a timely fashion Mar 26 04:25:06 room volumio[1288]: info: Completed starting MyVolumio Plugin Mar 26 04:25:06 room volumio[1288]: [Metrics] CommandRouter: 56s 879.25ms Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::volumiosetStartupVolume Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 04:25:06 room volumio[1288]: info: VolumeController:: Setting startup Volume 100 Mar 26 04:25:06 room volumio[1288]: info: VolumeController::SetAlsaVolume100 Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::Close All Modals sent Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::Close All Modals sent Mar 26 04:25:06 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:06 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:06 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:07 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 26 04:25:07 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 04:25:07 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 26 04:25:08 room volumio5-onboarding[1615]: time=2026-03-26T04:25:08.851+09:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.0.25:52598 error="read tcp 192.168.0.8:7331->192.168.0.25:52598: read: connection reset by peer" Mar 26 04:25:08 room volumio5-onboarding[1615]: time=2026-03-26T04:25:08.851+09:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.0.25:52598 Mar 26 04:25:08 room volumio5-onboarding[1615]: time=2026-03-26T04:25:08.851+09:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.0.25:52598 Mar 26 04:25:13 room volumio[1288]: info: BOOT COMPLETED Mar 26 04:25:30 room volumio5-onboarding[1615]: time=2026-03-26T04:25:30.295+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.25:52684 Mar 26 04:25:36 room sudo[2196]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 04:25:36 room sudo[2196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 04:25:36 room sudo[2198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 04:25:36 room sudo[2198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 04:25:36 room sudo[2196]: pam_unix(sudo:session): session closed for user root Mar 26 04:25:36 room sudo[2198]: pam_unix(sudo:session): session closed for user root Mar 26 04:25:36 room volumio[1288]: verbose: New Socket.io Connection to 192.168.0.8 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 12; SM-N976N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 26 04:25:36 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 26 04:25:37 room volumio[1288]: verbose: New Socket.io Connection to 192.168.0.8 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 12; SM-N976N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 04:25:37 room sudo[2204]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetVisibleSources Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 04:25:37 room sudo[2204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 04:25:37 room sudo[2204]: pam_unix(sudo:session): session closed for user root Mar 26 04:25:37 room sudo[2202]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 04:25:37 room sudo[2202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetQueue Mar 26 04:25:37 room volumio[1288]: info: CoreStateMachine::getQueue Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getQueue Mar 26 04:25:37 room volumio[1288]: info: Listing playlists Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 26 04:25:37 room sudo[2202]: pam_unix(sudo:session): session closed for user root Mar 26 04:25:37 room volumio[1288]: info: Received Get System Info Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:37 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 26 04:25:37 room volumio[1288]: verbose: New Socket.io Connection to 192.168.0.8 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 12; SM-N976N Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetVisibleSources Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 26 04:25:37 room volumio[1288]: info: Received Get System Info Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:37 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:37 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:37 room volumio[1288]: info: Listing playlists Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 26 04:25:37 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 04:25:38 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 04:25:39 room volumio[1288]: info: Received Get System Info Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:39 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:39 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 04:25:39 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 26 04:25:41 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 04:25:41 room volumio[1288]: info: Received Get System Info Mar 26 04:25:41 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:41 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:41 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:41 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:41 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:41 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 04:25:42 room volumio[1288]: info: Received Get System Info Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:42 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:42 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 04:25:42 room volumio[1288]: info: Received Get System Info Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:42 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:42 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:42 room volumio[1288]: info: CoreCommandRouter::volumioGetQueue Mar 26 04:25:42 room volumio[1288]: info: CoreStateMachine::getQueue Mar 26 04:25:42 room volumio[1288]: info: CorePlayQueue::getQueue Mar 26 04:25:43 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 04:25:43 room volumio[1288]: info: Received Get System Info Mar 26 04:25:43 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:43 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:43 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:43 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:43 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:43 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:47 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 26 04:25:48 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 26 04:25:48 room volumio[1288]: info: CURURI: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett Mar 26 04:25:48 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:48 room volumio[1288]: info: Preloading song: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Preloading song: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/02 - Keith Jarrett - Köln, January 24, 1975, Part II a (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Preloading song: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/03 - Keith Jarrett - Köln, January 24, 1975, Part II b (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Preloading song: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/04 - Keith Jarrett - Köln, January 24, 1975, Part II c (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Preloading song: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/The Köln Concert - Keith Jarrett.m3u Mar 26 04:25:48 room volumio[1288]: info: Exploding uri music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac in service mpd Mar 26 04:25:48 room volumio[1288]: info: ALBUMART /albumart?cacheid=643&web=Keith%20Jarrett/The%20K%C3%B6ln%20Concert/extralarge&path=%2Fmnt%2FUSB%2FC44C70DB4C70C9A6%2Fmusic%2FThe%20K%C3%B6ln%20Concert%20-%20Keith%20Jarrett%2F01%20-%20Keith%20Jarrett%20-%20K%C3%B6ln%2C%20January%2024%2C%201975%2C%20Part%20I%20(Live).flac&metadata=false Mar 26 04:25:48 room volumio[1288]: info: URI /mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Exploding uri music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/02 - Keith Jarrett - Köln, January 24, 1975, Part II a (Live).flac in service mpd Mar 26 04:25:48 room volumio[1288]: info: ALBUMART /albumart?cacheid=643&web=Keith%20Jarrett/The%20K%C3%B6ln%20Concert/extralarge&path=%2Fmnt%2FUSB%2FC44C70DB4C70C9A6%2Fmusic%2FThe%20K%C3%B6ln%20Concert%20-%20Keith%20Jarrett%2F02%20-%20Keith%20Jarrett%20-%20K%C3%B6ln%2C%20January%2024%2C%201975%2C%20Part%20II%20a%20(Live).flac&metadata=false Mar 26 04:25:48 room volumio[1288]: info: URI /mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/02 - Keith Jarrett - Köln, January 24, 1975, Part II a (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Exploding uri music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/03 - Keith Jarrett - Köln, January 24, 1975, Part II b (Live).flac in service mpd Mar 26 04:25:48 room volumio[1288]: info: ALBUMART /albumart?cacheid=643&web=Keith%20Jarrett/The%20K%C3%B6ln%20Concert/extralarge&path=%2Fmnt%2FUSB%2FC44C70DB4C70C9A6%2Fmusic%2FThe%20K%C3%B6ln%20Concert%20-%20Keith%20Jarrett%2F03%20-%20Keith%20Jarrett%20-%20K%C3%B6ln%2C%20January%2024%2C%201975%2C%20Part%20II%20b%20(Live).flac&metadata=false Mar 26 04:25:48 room volumio[1288]: info: URI /mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/03 - Keith Jarrett - Köln, January 24, 1975, Part II b (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Exploding uri music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/04 - Keith Jarrett - Köln, January 24, 1975, Part II c (Live).flac in service mpd Mar 26 04:25:48 room volumio[1288]: info: ALBUMART /albumart?cacheid=643&web=Keith%20Jarrett/The%20K%C3%B6ln%20Concert/extralarge&path=%2Fmnt%2FUSB%2FC44C70DB4C70C9A6%2Fmusic%2FThe%20K%C3%B6ln%20Concert%20-%20Keith%20Jarrett%2F04%20-%20Keith%20Jarrett%20-%20K%C3%B6ln%2C%20January%2024%2C%201975%2C%20Part%20II%20c%20(Live).flac&metadata=false Mar 26 04:25:48 room volumio[1288]: info: URI /mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/04 - Keith Jarrett - Köln, January 24, 1975, Part II c (Live).flac Mar 26 04:25:48 room volumio[1288]: info: Exploding uri music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/The Köln Concert - Keith Jarrett.m3u in service mpd Mar 26 04:25:50 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::ClearQueue Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::stop Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::clearPlayQueue Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::saveQueue Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioPushQueue Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::addQueueItems Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::addQueueItems Mar 26 04:25:50 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:50 room volumio[1288]: info: Adding Item to queue: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Using cached record of: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioPushQueue Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::saveQueue Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::updateTrackBlock Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrackBlock Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioPlay Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::play index 0 Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::addQueueItems Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::addQueueItems Mar 26 04:25:50 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:50 room volumio[1288]: info: Adding Item to queue: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/02 - Keith Jarrett - Köln, January 24, 1975, Part II a (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Using cached record of: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/02 - Keith Jarrett - Köln, January 24, 1975, Part II a (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Adding Item to queue: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/03 - Keith Jarrett - Köln, January 24, 1975, Part II b (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Using cached record of: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/03 - Keith Jarrett - Köln, January 24, 1975, Part II b (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Adding Item to queue: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/04 - Keith Jarrett - Köln, January 24, 1975, Part II c (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Using cached record of: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/04 - Keith Jarrett - Köln, January 24, 1975, Part II c (Live).flac Mar 26 04:25:50 room volumio[1288]: info: Adding Item to queue: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/The Köln Concert - Keith Jarrett.m3u Mar 26 04:25:50 room volumio[1288]: info: Using cached record of: music-library/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/The Köln Concert - Keith Jarrett.m3u Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::stop Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioPushQueue Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::saveQueue Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::play index undefined Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::updateTrackBlock Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrackBlock Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::startPlaybackTimer Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::clearAddPlayTracks USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand stop took 117 milliseconds Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand clear Mar 26 04:25:50 room upmpdcli[1699]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand clear took 23 milliseconds Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand add "USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: error: updateQueue error: null Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 31ms Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand add "USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" took 26 milliseconds Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 17ms Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 10ms Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand play Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces system playlist update Mar 26 04:25:50 room volumio[1288]: info: Ignoring MPD Status Update Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 29ms Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand play took 24 milliseconds Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 20ms Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: ------------------------------ 20ms Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand status took 17 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand status took 19 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand status took 11 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand status took 7 milliseconds Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: Mar 26 04:25:50 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand playlistinfo took 15 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand playlistinfo took 19 milliseconds Mar 26 04:25:50 room volumio[1288]: info: sendMpdCommand playlistinfo took 19 milliseconds Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:50 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:50 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:50 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::syncState currentStatus stop Mar 26 04:25:50 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:50 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:50 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::syncState currentStatus play Mar 26 04:25:50 room volumio[1288]: info: Received an update from plugin. extracting info from payload Mar 26 04:25:50 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:50 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 04:25:50 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:51 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState currentStatus play Mar 26 04:25:51 room volumio[1288]: info: Received an update from plugin. extracting info from payload Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:51 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState currentStatus play Mar 26 04:25:51 room volumio[1288]: info: Received an update from plugin. extracting info from payload Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 176ms Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.141+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.142+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.165+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.165+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.165+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.165+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.165+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.166+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.173+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.173+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.182+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.182+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 554ms Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 544ms Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 542ms Mar 26 04:25:51 room volumio[1288]: info: sendMpdCommand status took 558 milliseconds Mar 26 04:25:51 room volumio[1288]: info: sendMpdCommand status took 557 milliseconds Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:25:51 room volumio[1288]: info: sendMpdCommand playlistinfo took 280 milliseconds Mar 26 04:25:51 room volumio[1288]: info: sendMpdCommand playlistinfo took 279 milliseconds Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:51 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:25:51 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:51 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState currentStatus play Mar 26 04:25:51 room volumio[1288]: info: Received an update from plugin. extracting info from payload Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":1562,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"454 Kbps","isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:25:51 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState stateService play Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::syncState currentStatus play Mar 26 04:25:51 room volumio[1288]: info: Received an update from plugin. extracting info from payload Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:25:51 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:51 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.879+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.879+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.881+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.882+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.883+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.884+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.886+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_PLAYING positionMs=848 volume=100 Mar 26 04:25:51 room volumio5-onboarding[1615]: time=2026-03-26T04:25:51.886+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 949ms Mar 26 04:25:51 room volumio[1288]: info: ------------------------------ 949ms Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 04:25:56 room volumio[1288]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 26 04:25:56 room volumio[1288]: info: Received Get System Version Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 04:25:56 room volumio[1288]: info: Received Get System Info Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 04:25:56 room volumio[1288]: info: Discovery: Getting this device information Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::volumioGetState Mar 26 04:25:56 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:25:56 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 04:25:57 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 04:25:57 room volumio[1288]: info: [DarkAscendants] handleBrowseUri: darkascendants Mar 26 04:25:58 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:58 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:58 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:58 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:58 room volumio[1288]: info: Preload queue cleared Mar 26 04:25:59 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 04:25:59 room volumio[1288]: info: [DarkAscendants] handleBrowseUri: darkascendants/home Mar 26 04:26:00 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:00 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:00 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:00 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:02 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 04:26:02 room volumio[1288]: info: [DarkAscendants] handleBrowseUri: darkascendants/playlist/0027f014461848c5fb3dc4d484f9ab Mar 26 04:26:04 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/476638898 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/467444955 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/398950798 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/285885742 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/421142662 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/475307603 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/473817583 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/398950807 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/409386876 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/444492180 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/437775283 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/475307601 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/475307602 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/443895277 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/443204062 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/401093310 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/455140596 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/480153829 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/432891334 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/434078544 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/439232409 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/388654889 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/359746194 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/419058757 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/401093321 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/436441046 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/409386866 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/393618685 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/471694602 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/434078552 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/418784205 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/364329267 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/436206991 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/403486221 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/426651227 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/256039337 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/446405016 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/426214797 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/432891346 Mar 26 04:26:04 room volumio[1288]: info: Preloading song: darkascendants/track/423495073 Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/476638898 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/467444955 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/398950798 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/285885742 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/421142662 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/475307603 in service dark_ascendants Mar 26 04:26:04 room volumio[1288]: info: Exploding uri darkascendants/track/473817583 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/398950807 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/409386876 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/444492180 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/437775283 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/475307601 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/475307602 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/443895277 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/443204062 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/401093310 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/455140596 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/480153829 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/432891334 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/434078544 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/439232409 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/388654889 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/359746194 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/419058757 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/401093321 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/436441046 in service dark_ascendants Mar 26 04:26:05 room volumio[1288]: info: Exploding uri darkascendants/track/409386866 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/393618685 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/471694602 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/434078552 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/418784205 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/364329267 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/436206991 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/403486221 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/426651227 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/256039337 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/446405016 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/426214797 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/432891346 in service dark_ascendants Mar 26 04:26:06 room volumio[1288]: info: Exploding uri darkascendants/track/423495073 in service dark_ascendants Mar 26 04:26:07 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::ClearQueue Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::stop Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::stPlaybackTimer Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::updateTrackBlock Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::getTrackBlock Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::serviceStop Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::serviceStop Mar 26 04:26:07 room volumio[1288]: info: ControllerMpd::stop Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::clearPlayQueue Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::saveQueue Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::volumioPushQueue Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::addQueueItems Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::addQueueItems Mar 26 04:26:07 room volumio[1288]: info: Preload queue cleared Mar 26 04:26:07 room volumio[1288]: info: Adding Item to queue: darkascendants/playlist/0027f014461848c5fb3dc4d484f9ab Mar 26 04:26:07 room volumio[1288]: info: Exploding uri darkascendants/playlist/0027f014461848c5fb3dc4d484f9ab in service dark_ascendants Mar 26 04:26:07 room volumio5-onboarding[1615]: time=2026-03-26T04:26:07.608+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:07 room volumio5-onboarding[1615]: time=2026-03-26T04:26:07.609+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id="mnt/USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac" title="Köln, January 24, 1975, Part I (Live)" Mar 26 04:26:07 room volumio[1288]: info: Mar 26 04:26:07 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand stop took 257 milliseconds Mar 26 04:26:07 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:26:07 room volumio[1288]: info: Mar 26 04:26:07 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:26:07 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:26:07 room volumio[1288]: info: Mar 26 04:26:07 room volumio[1288]: ---------------------------- MPD announces state update: player Mar 26 04:26:07 room volumio[1288]: info: ControllerMpd::getState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand status Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand status took 40 milliseconds Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand status took 26 milliseconds Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand status took 7 milliseconds Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseState Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand playlistinfo took 74 milliseconds Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand playlistinfo took 74 milliseconds Mar 26 04:26:07 room volumio[1288]: info: sendMpdCommand playlistinfo took 74 milliseconds Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:26:07 room volumio[1288]: verbose: ControllerMpd::parseTrackInfo Mar 26 04:26:07 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 04:26:07 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:07 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:07 room volumio[1288]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:26:07 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::syncState stateService stop Mar 26 04:26:07 room volumio[1288]: info: CoreStateMachine::syncState currentStatus stop Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: No code Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:26:08 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::syncState stateService stop Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::syncState currentStatus stop Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: No code Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: ControllerMpd::pushState Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::servicePushState Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Köln, January 24, 1975, Part I (Live)","artist":"Keith Jarrett","album":"The Köln Concert","uri":"USB/C44C70DB4C70C9A6/music/The Köln Concert - Keith Jarrett/01 - Keith Jarrett - Köln, January 24, 1975, Part I (Live).flac","trackType":"flac"} Mar 26 04:26:08 room volumio[1288]: verbose: CURRENT POSITION 0 Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::syncState stateService stop Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::syncState currentStatus stop Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio[1288]: info: No code Mar 26 04:26:08 room volumio[1288]: info: CoreStateMachine::pushState Mar 26 04:26:08 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:08 room volumio[1288]: info: CoreCommandRouter::volumioPushState Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.166+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.166+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.176+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.176+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.196+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.196+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio5-onboarding[1615]: time=2026-03-26T04:26:08.196+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:52684,00:00:00:00:00:00%02 @ 0x34c2990" id= title= Mar 26 04:26:08 room volumio[1288]: info: ------------------------------ 820ms Mar 26 04:26:08 room volumio[1288]: info: ------------------------------ 769ms Mar 26 04:26:08 room volumio[1288]: info: ------------------------------ 757ms Mar 26 04:26:08 room volumio[1288]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 26 04:26:09 room volumio[1288]: info: CoreCommandRouter::volumioPushQueue Mar 26 04:26:09 room volumio[1288]: info: CorePlayQueue::saveQueue Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::updateTrackBlock Mar 26 04:26:09 room volumio[1288]: info: CorePlayQueue::getTrackBlock Mar 26 04:26:09 room volumio[1288]: info: CoreCommandRouter::volumioPlay Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::play index 0 Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::stop Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::play index undefined Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 04:26:09 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:09 room volumio[1288]: info: CoreStateMachine::startPlaybackTimer Mar 26 04:26:09 room volumio[1288]: info: CorePlayQueue::getTrack 0 Mar 26 04:26:09 room volumio[1288]: info: [DarkAscendants] clearAddPlayTrack quality=LOSSLESS useHiResProxy=true raw=true Mar 26 04:26:09 room volumio[1288]: info: [DarkAscendants] clearAddPlayTrack: darkascendants/track/476638898 Mar 26 04:26:10 room volumio[1288]: error: [DarkAscendants] clearAddPlayTrack error: No playable stream for track 476638898 Mar 26 04:26:10 room volumio[1288]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 04:26:10 room volumio[1288]: Error: No playable stream for track 476638898 Mar 26 04:26:10 room volumio[1288]: at TidalApi.getStreamUrl (/data/plugins/music_service/dark_ascendants/tidal-api.js:395:11) Mar 26 04:26:10 room volumio[1288]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Mar 26 04:26:10 room volumio[1288]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 04:26:13 room sudo[2295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 04:25' Mar 26 04:26:13 room sudo[2295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"