Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:00 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:00 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:00 volumio volumio[1052]: verbose: New Socket.io Connection to 192.168.2.29:3000 from 192.168.2.18 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:00 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 04 17:10:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 04 17:10:01 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:01 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:02 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:02 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:02 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:02 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:02 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:02 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:03 volumio sudo[2085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 04 17:10:03 volumio sudo[2085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:10:03 volumio sudo[2087]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 04 17:10:03 volumio sudo[2087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:10:03 volumio sudo[2085]: pam_unix(sudo:session): session closed for user root Sep 04 17:10:03 volumio sudo[2087]: pam_unix(sudo:session): session closed for user root Sep 04 17:10:03 volumio volumio[1052]: verbose: New Socket.io Connection to 192.168.2.29 from 192.168.2.18 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Sep 04 17:10:03 volumio sudo[2094]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 04 17:10:03 volumio sudo[2094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:10:03 volumio sudo[2096]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 04 17:10:03 volumio sudo[2096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:10:03 volumio sudo[2094]: pam_unix(sudo:session): session closed for user root Sep 04 17:10:03 volumio sudo[2096]: pam_unix(sudo:session): session closed for user root Sep 04 17:10:04 volumio volumio[1052]: verbose: New Socket.io Connection to 192.168.2.29 from 192.168.2.18 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::volumioGetVisibleSources Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:04 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 04 17:10:04 volumio volumio[1052]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 04 17:10:04 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:04 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:04 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:04 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:04 volumio volumio[1052]: info: Listing playlists Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 04 17:10:04 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 17:10:05 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:05 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:05 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:05 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 04 17:10:06 volumio volumio[1052]: info: CoreCommandRouter::volumioPlay Sep 04 17:10:06 volumio volumio[1052]: info: CoreStateMachine::play index undefined Sep 04 17:10:06 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:10:06 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:06 volumio volumio[1052]: info: CoreStateMachine::startPlaybackTimer Sep 04 17:10:06 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:06 volumio volumio[1052]: info: [1756980606260] ControllerQobuz::clearAddPlayTrack Sep 04 17:10:06 volumio volumio[1052]: info: getStreamUrl took 541 milliseconds Sep 04 17:10:06 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 17:10:06 volumio volumio[1052]: info: sendMpdCommand stop took 1 milliseconds Sep 04 17:10:06 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand clear Sep 04 17:10:06 volumio volumio[1052]: info: Sep 04 17:10:06 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:06 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:06 volumio volumio[1052]: info: sendMpdCommand clear took 0 milliseconds Sep 04 17:10:06 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k" Sep 04 17:10:06 volumio volumio[1052]: info: Sep 04 17:10:06 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:06 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:06 volumio volumio[1052]: info: Sep 04 17:10:06 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:06 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:06 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:10:06 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:10:07 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:10:07 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k" Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 340ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 340ms Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k" took 0 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand play Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:07 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:07 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:10:07 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand play took 2 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 2ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 13 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 13 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 13 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 1 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 1 milliseconds Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"474 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 16ms Sep 04 17:10:07 volumio volumio[1052]: info: Sep 04 17:10:07 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand status took 2 milliseconds Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":456,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:10:07 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1209,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:10:07 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1209,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:10:07 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1209,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:10:07 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 56ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 56ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 45ms Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 45ms Sep 04 17:10:07 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 41 milliseconds Sep 04 17:10:07 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:10:07 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:10:07 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:10:07 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1209,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"457 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984189&hmac=cj7t3vvBQIpHjBXaRcxB3_e4b6k","trackType":"qobuz"} Sep 04 17:10:07 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:10:07 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:07 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:07 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:07 volumio volumio[1052]: info: ------------------------------ 56ms Sep 04 17:10:09 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 17:10:09 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:09 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:09 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:09 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:09 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:09 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 17:10:10 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:10 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 17:10:10 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:10 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:10 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:11 volumio go-librespot[1743]: time="2025-09-04T17:10:11+07:00" level=trace msg="sent dealer ping" Sep 04 17:10:11 volumio go-librespot[1743]: time="2025-09-04T17:10:11+07:00" level=trace msg="received dealer pong" Sep 04 17:10:13 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 04 17:10:22 volumio volumio[1052]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 04 17:10:22 volumio volumio[1052]: info: Received Get System Version Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 17:10:22 volumio volumio[1052]: info: Received Get System Info Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:22 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:22 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:27 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:27 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:27 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 04 17:10:27 volumio dbus-daemon[825]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=2163 comm="timedatectl show --property=NTPSynchronized --valu") Sep 04 17:10:27 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 04 17:10:27 volumio dbus-daemon[825]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 04 17:10:27 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 04 17:10:27 volumio setdatetime-helper.sh[2162]: Time is already synchronized. Sep 04 17:10:27 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 04 17:10:27 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 04 17:10:36 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 04 17:10:41 volumio go-librespot[1743]: time="2025-09-04T17:10:41+07:00" level=trace msg="sent dealer ping" Sep 04 17:10:41 volumio go-librespot[1743]: time="2025-09-04T17:10:41+07:00" level=trace msg="received dealer pong" Sep 04 17:10:55 volumio volumio[1052]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:55 volumio volumio[1052]: info: Restoring Previous Volume level: 100 false false Sep 04 17:10:55 volumio volumio[1052]: info: Volume configurations have been set Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 04 17:10:55 volumio volumio[1052]: info: Updating Volume Controller Parameters: Device: 5 Name: E30 II Mixer: E30 II Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 04 17:10:55 volumio volumio[1052]: info: Disabling external Volume Control Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 04 17:10:55 volumio volumio[1052]: info: VolumeController:: Volume=100 Mute =false Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:55 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:10:55 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:55 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:55 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:55 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:10:57 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:10:57 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:10:57 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:10:57 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:57 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:10:57 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 04 17:10:59 volumio volumio[1052]: info: VolumeController::SetAlsaVolume100 Sep 04 17:10:59 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:10:59 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:10:59 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:10:59 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:10:59 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:10:59 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:10:59 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:11:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:00 volumio volumio[1052]: info: VolumeController:: Setting startup Volume 100 Sep 04 17:11:00 volumio volumio[1052]: info: VolumeController::SetAlsaVolume100 Sep 04 17:11:00 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:11:00 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:11:00 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:11:00 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:11:00 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:11:00 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:11:00 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:11:10 volumio go-librespot[1743]: time="2025-09-04T17:11:10+07:00" level=trace msg="received accesspoint ping" Sep 04 17:11:11 volumio go-librespot[1743]: time="2025-09-04T17:11:11+07:00" level=trace msg="received accesspoint pong ack" Sep 04 17:11:11 volumio go-librespot[1743]: time="2025-09-04T17:11:11+07:00" level=trace msg="sent dealer ping" Sep 04 17:11:11 volumio go-librespot[1743]: time="2025-09-04T17:11:11+07:00" level=trace msg="received dealer pong" Sep 04 17:11:24 volumio volumio[1052]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Sep 04 17:11:24 volumio sudo[2333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 17:11:24 volumio sudo[2333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:11:24 volumio sudo[2333]: pam_unix(sudo:session): session closed for user root Sep 04 17:11:24 volumio volumio[1052]: info: MPD Permissions set Sep 04 17:11:24 volumio sudo[2335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 17:11:24 volumio sudo[2335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 04 17:11:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 04 17:11:24 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 17:11:24 volumio systemd[1]: mpd.service: Deactivated successfully. Sep 04 17:11:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 04 17:11:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Sep 04 17:11:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 04 17:11:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 04 17:11:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 04 17:11:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Sep 04 17:11:24 volumio sudo[2347]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 04 17:11:24 volumio sudo[2347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 04 17:11:24 volumio sudo[2347]: pam_unix(sudo:session): session closed for user root Sep 04 17:11:24 volumio mpd[2349]: 2025-09-04T17:11:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 04 17:11:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Sep 04 17:11:24 volumio sudo[2335]: pam_unix(sudo:session): session closed for user root Sep 04 17:11:24 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:11:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 04 17:11:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 04 17:11:27 volumio volumio[1052]: info: Discovery: Getting this device information Sep 04 17:11:27 volumio volumio[1052]: info: CoreCommandRouter::volumioGetState Sep 04 17:11:27 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 04 17:11:39 volumio volumio[1052]: info: CoreCommandRouter::volumioGetQueue Sep 04 17:11:39 volumio volumio[1052]: info: CoreStateMachine::getQueue Sep 04 17:11:39 volumio volumio[1052]: info: CorePlayQueue::getQueue Sep 04 17:11:39 volumio volumio[1052]: info: Executing endpoint metavolumio Sep 04 17:11:39 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 04 17:11:39 volumio volumio[1052]: info: Executing endpoint metavolumio Sep 04 17:11:39 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 04 17:11:41 volumio go-librespot[1743]: time="2025-09-04T17:11:41+07:00" level=trace msg="sent dealer ping" Sep 04 17:11:41 volumio go-librespot[1743]: time="2025-09-04T17:11:41+07:00" level=trace msg="received dealer pong" Sep 04 17:11:41 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:41 volumio volumio[1052]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::ClearQueue Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::stPlaybackTimer Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:41 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:11:41 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:11:41 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:11:41 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::serviceStop Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:41 volumio volumio[1052]: info: CoreCommandRouter::serviceStop Sep 04 17:11:41 volumio volumio[1052]: info: [1756980701492] ControllerQobuz::stop Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 04 17:11:41 volumio volumio[1052]: info: ControllerMpd::stop Sep 04 17:11:41 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::clearPlayQueue Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:41 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:41 volumio volumio[1052]: info: CoreStateMachine::addQueueItems Sep 04 17:11:41 volumio volumio[1052]: info: CorePlayQueue::addQueueItems Sep 04 17:11:41 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:41 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580375 Sep 04 17:11:41 volumio volumio[1052]: info: Exploding uri qobuz://song/283580375 in service qobuz Sep 04 17:11:41 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:41 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580376 Sep 04 17:11:41 volumio volumio[1052]: info: Exploding uri qobuz://song/283580376 in service qobuz Sep 04 17:11:41 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:41 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:11:41 volumio volumio[1052]: info: sendMpdCommand stop took 18 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 527 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 722 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:42 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:42 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:42 volumio volumio[1052]: info: CoreCommandRouter::volumioPlay Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::play index 1 Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::addQueueItems Sep 04 17:11:42 volumio volumio[1052]: info: CorePlayQueue::addQueueItems Sep 04 17:11:42 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580377 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580377 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580378 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580378 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580379 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580379 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580380 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580380 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580381 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580381 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580382 Sep 04 17:11:42 volumio volumio[1052]: info: Exploding uri qobuz://song/283580382 in service qobuz Sep 04 17:11:42 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::play index undefined Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:42 volumio volumio[1052]: info: CorePlayQueue::getTrack 1 Sep 04 17:11:42 volumio volumio[1052]: info: CoreStateMachine::startPlaybackTimer Sep 04 17:11:42 volumio volumio[1052]: info: CorePlayQueue::getTrack 1 Sep 04 17:11:42 volumio volumio[1052]: info: CoreCommandRouter::volumioGetVisibleSources Sep 04 17:11:42 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 17:11:42 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 04 17:11:42 volumio volumio[1052]: info: [1756980702220] ControllerQobuz::clearAddPlayTrack Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 465 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: getStreamUrl took 483 milliseconds Sep 04 17:11:42 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 17:11:42 volumio volumio[1052]: info: sendMpdCommand stop took 0 milliseconds Sep 04 17:11:42 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand clear Sep 04 17:11:42 volumio volumio[1052]: info: Sep 04 17:11:42 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:42 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:42 volumio volumio[1052]: info: sendMpdCommand clear took 0 milliseconds Sep 04 17:11:42 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580376&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984285&hmac=EhdWRDMsDHF9x7oApIcwidToDD8" Sep 04 17:11:42 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:11:42 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 519 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 529 milliseconds Sep 04 17:11:42 volumio volumio[1052]: info: explodeUri took 617 milliseconds Sep 04 17:11:43 volumio volumio[1052]: info: explodeUri took 832 milliseconds Sep 04 17:11:43 volumio volumio[1052]: info: explodeUri took 841 milliseconds Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::ClearQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::clearPlayQueue Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::addQueueItems Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::addQueueItems Sep 04 17:11:43 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580375 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580375 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580376 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580376 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580377 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580377 Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioPlay Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::play index 2 Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::addQueueItems Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::addQueueItems Sep 04 17:11:43 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580378 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580378 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580379 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580379 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580380 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580380 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580381 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580381 Sep 04 17:11:43 volumio volumio[1052]: info: Adding Item to queue: qobuz://song/283580382 Sep 04 17:11:43 volumio volumio[1052]: info: Using cached record of: qobuz://song/283580382 Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:43 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::play index undefined Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::getTrack 2 Sep 04 17:11:43 volumio volumio[1052]: info: CoreStateMachine::startPlaybackTimer Sep 04 17:11:43 volumio volumio[1052]: info: CorePlayQueue::getTrack 2 Sep 04 17:11:43 volumio volumio[1052]: info: [1756980703578] ControllerQobuz::clearAddPlayTrack Sep 04 17:11:43 volumio volumio[1052]: info: getStreamUrl took 376 milliseconds Sep 04 17:11:43 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580376&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984285&hmac=EhdWRDMsDHF9x7oApIcwidToDD8" Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand stop took 794 milliseconds Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand clear Sep 04 17:11:44 volumio volumio[1052]: info: Sep 04 17:11:44 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:44 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:44 volumio volumio[1052]: info: Sep 04 17:11:44 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:44 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580376&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984285&hmac=EhdWRDMsDHF9x7oApIcwidToDD8" took 1 milliseconds Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand clear took 0 milliseconds Sep 04 17:11:44 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand play Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580377&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984286&hmac=HZjE1OPKgAYNgq9p6TfWdThRxNY" Sep 04 17:11:44 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:11:44 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:11:44 volumio volumio[1052]: info: ------------------------------ 0ms Sep 04 17:11:44 volumio volumio[1052]: info: ------------------------------ 0ms Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand play took 0 milliseconds Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580377&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984286&hmac=HZjE1OPKgAYNgq9p6TfWdThRxNY" Sep 04 17:11:44 volumio volumio[1052]: info: Sep 04 17:11:44 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:44 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580377&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984286&hmac=HZjE1OPKgAYNgq9p6TfWdThRxNY" took 0 milliseconds Sep 04 17:11:44 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 04 17:11:44 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand play Sep 04 17:11:44 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:11:44 volumio volumio[1052]: info: sendMpdCommand play took 1 milliseconds Sep 04 17:11:46 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:46 volumio volumio[1052]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::ClearQueue Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::clearPlayQueue Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:46 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::addQueueItems Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::addQueueItems Sep 04 17:11:46 volumio volumio[1052]: info: Preload queue cleared Sep 04 17:11:46 volumio volumio[1052]: info: Adding Item to queue: qobuz://album/wi4fbn8dh4cra Sep 04 17:11:46 volumio volumio[1052]: info: Exploding uri qobuz://album/wi4fbn8dh4cra in service qobuz Sep 04 17:11:46 volumio volumio[1052]: https://prod.vlmapi.io/v2/qobuz/explodeUri Sep 04 17:11:46 volumio volumio[1052]: info: explodeUri took 514 milliseconds Sep 04 17:11:46 volumio volumio[1052]: info: CoreCommandRouter::volumioPushQueue Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::saveQueue Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::updateTrackBlock Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::getTrackBlock Sep 04 17:11:46 volumio volumio[1052]: info: CoreCommandRouter::volumioPlay Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::play index 0 Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::stop Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::play index undefined Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:46 volumio volumio[1052]: info: CoreStateMachine::startPlaybackTimer Sep 04 17:11:46 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:46 volumio volumio[1052]: info: [1756980706808] ControllerQobuz::clearAddPlayTrack Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand status took 44 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand status took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:11:47 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:47 volumio volumio[1052]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 45ms Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:11:47 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:47 volumio volumio[1052]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 3ms Sep 04 17:11:47 volumio volumio[1052]: info: getStreamUrl took 581 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand stop took 3 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand clear Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:47 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand status took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand clear took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A" Sep 04 17:11:47 volumio volumio[1052]: error: updateQueue error: null Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:11:47 volumio volumio[1052]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A" Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces system playlist update Sep 04 17:11:47 volumio volumio[1052]: info: Ignoring MPD Status Update Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A" took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand play Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 1ms Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand play took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:11:47 volumio volumio[1052]: info: Sep 04 17:11:47 volumio volumio[1052]: ---------------------------- MPD announces state update: player Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand status took 11 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::getState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand status Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand status took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseState Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:11:47 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:47 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A","trackType":"qobuz"} Sep 04 17:11:47 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus stop Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 12ms Sep 04 17:11:47 volumio volumio[1052]: info: sendMpdCommand playlistinfo took 0 milliseconds Sep 04 17:11:47 volumio volumio[1052]: verbose: ControllerMpd::parseTrackInfo Sep 04 17:11:47 volumio volumio[1052]: info: ControllerMpd::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::servicePushState Sep 04 17:11:47 volumio volumio[1052]: info: CorePlayQueue::getTrack 0 Sep 04 17:11:47 volumio volumio[1052]: verbose: STATE SERVICE {"status":"play","position":0,"seek":456,"duration":143,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"430 Kbps","isStreaming":false,"title":"file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=6803077&eid=283580375&fmt=6&profile=raw&app_id=539451548&cid=3025636&etsp=1756984289&hmac=e6HWIbaT0AXorbwcZo7EXF0G81A","trackType":"qobuz"} Sep 04 17:11:47 volumio volumio[1052]: verbose: CURRENT POSITION 0 Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::syncState stateService play Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::syncState currentStatus play Sep 04 17:11:47 volumio volumio[1052]: info: Received an update from plugin. extracting info from payload Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:11:47 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:11:47 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:11:47 volumio volumio[1052]: info: CoreStateMachine::pushState Sep 04 17:11:47 volumio volumio[1052]: info: CoreCommandRouter::volumioPushState Sep 04 17:11:47 volumio volumio[1052]: info: MRS: Pushing multiroomSync output update for this device Sep 04 17:11:47 volumio volumio[1052]: info: MRS: Pushing multiroomSync output Sep 04 17:11:47 volumio volumio[1052]: info: ------------------------------ 13ms Sep 04 17:11:47 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:11:47 volumio volumio[1052]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 04 17:11:55 volumio volumio[1052]: Searching all installed plugins Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: , search Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 04 17:11:55 volumio volumio[1052]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search Sep 04 17:11:55 volumio volumio[1052]: info: [youtube2] InnertubeLoader: creating Innertube instance... Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Sep 04 17:11:55 volumio volumio[1052]: info: [ytmusic] InnertubeLoader: creating Innertube instance... Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: 80s80s , search Sep 04 17:11:55 volumio volumio[1052]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Sep 04 17:11:57 volumio volumio[1052]: info: [ytmusic] InnertubeLoader: obtaining po_token by visitorData... Sep 04 17:11:57 volumio volumio[1052]: Use XMLElement.setAttribute instead Sep 04 17:11:57 volumio volumio[1052]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 17:11:57 volumio volumio[1052]: TypeError: children[i].attr(...).value is not a function Sep 04 17:11:57 volumio volumio[1052]: at /volumio/app/plugins/music_service/webradio/index.js:956:46 Sep 04 17:11:57 volumio volumio[1052]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Sep 04 17:11:57 volumio volumio[1052]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 17:11:57 volumio sudo[2454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-04 17:10' Sep 04 17:11:57 volumio sudo[2454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:47:19 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="f0f6a90610a0a39b2758a5b3958219e6"