Oct 11 18:29:02 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 11 18:29:04 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 11 18:29:04 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 11 18:29:15 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioNext Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::next Oct 11 18:29:17 volumio volumio[1383]: info: ControllerMpd::next Oct 11 18:29:17 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand next Oct 11 18:29:17 volumio volumio[1383]: info: Oct 11 18:29:17 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:17 volumio volumio[1383]: info: sendMpdCommand next took 10 milliseconds Oct 11 18:29:17 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:17 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:17 volumio volumio[1383]: info: sendMpdCommand status took 1 milliseconds Oct 11 18:29:17 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:17 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:17 volumio volumio[1383]: info: CorePlayQueue::getTrack 0 Oct 11 18:29:17 volumio volumio[1383]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 11 18:29:17 volumio volumio[1383]: verbose: CURRENT POSITION 0 Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::syncState stateService stop Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:17 volumio volumio[1383]: info: No code Oct 11 18:29:17 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:17 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.821+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=105119 volume=100 Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.821+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.822+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=105119 volume=100 Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.822+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=105119 volume=100 Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.822+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:17 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:17.822+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:17 volumio volumio[1383]: info: ------------------------------ 11ms Oct 11 18:29:17 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:17 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:17 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:17 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:20 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:20 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 11 18:29:20 volumio volumio[1383]: info: CoreCommandRouter::volumioPlay Oct 11 18:29:20 volumio volumio[1383]: info: CoreStateMachine::play index undefined Oct 11 18:29:20 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 18:29:20 volumio volumio[1383]: info: CorePlayQueue::getTrack 0 Oct 11 18:29:20 volumio volumio[1383]: info: CoreStateMachine::startPlaybackTimer Oct 11 18:29:20 volumio volumio[1383]: info: CorePlayQueue::getTrack 0 Oct 11 18:29:20 volumio volumio[1383]: info: [1791732560368] ControllerQobuz::clearAddPlayTrack Oct 11 18:29:21 volumio volumio[1383]: info: getStreamUrl took 1088 milliseconds Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand stop Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand stop took 2 milliseconds Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clear Oct 11 18:29:21 volumio volumio[1383]: info: Oct 11 18:29:21 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:21 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand clear took 0 milliseconds Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8" Oct 11 18:29:21 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:21 volumio volumio[1383]: info: ------------------------------ 1ms Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::volumioNext Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::next Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::stop Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::play index undefined Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 18:29:21 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::startPlaybackTimer Oct 11 18:29:21 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:21 volumio volumio[1383]: info: [1791732561505] ControllerQobuz::clearAddPlayTrack Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::updateTrackBlock Oct 11 18:29:21 volumio volumio[1383]: info: CorePlayQueue::getTrackBlock Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8" Oct 11 18:29:21 volumio volumio[1383]: info: Oct 11 18:29:21 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:21 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8" took 0 milliseconds Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand play Oct 11 18:29:21 volumio volumio[1383]: info: ------------------------------ 1ms Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand play took 0 milliseconds Oct 11 18:29:21 volumio volumio[1383]: info: Oct 11 18:29:21 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:21 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:21 volumio volumio[1383]: info: Oct 11 18:29:21 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:21 volumio volumio[1383]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": Unknown error 524 Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand status took 6 milliseconds Oct 11 18:29:21 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand clearerror took 1 milliseconds Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand status took 5 milliseconds Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:21 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:21 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:21 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":142,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8","trackType":"qobuz"} Oct 11 18:29:21 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:21 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:21 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:21 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:21.904+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=364 volume=100 Oct 11 18:29:21 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:21.904+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:21 volumio volumio[1383]: info: ------------------------------ 17ms Oct 11 18:29:21 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 11 18:29:21 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:21 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:21 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:21 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":142,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065576&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=2LnM2OSjCES5CZo9Xqy4Dmv5ov8","trackType":"qobuz"} Oct 11 18:29:21 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:21 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:21 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:21 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:21 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:21 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:21.910+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=364 volume=100 Oct 11 18:29:21 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:21.911+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:21 volumio volumio[1383]: info: ------------------------------ 18ms Oct 11 18:29:22 volumio volumio[1383]: info: getStreamUrl took 535 milliseconds Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand stop Oct 11 18:29:22 volumio volumio[1383]: info: Oct 11 18:29:22 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand stop took 3 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clear Oct 11 18:29:22 volumio volumio[1383]: info: Oct 11 18:29:22 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:22 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand status took 1 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand clear took 0 milliseconds Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE" Oct 11 18:29:22 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:22 volumio volumio[1383]: info: ------------------------------ 0ms Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:22 volumio volumio[1383]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 11 18:29:22 volumio volumio[1383]: info: ------------------------------ 2ms Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE" Oct 11 18:29:22 volumio volumio[1383]: info: Oct 11 18:29:22 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:22 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE" took 0 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand play Oct 11 18:29:22 volumio volumio[1383]: info: ------------------------------ 0ms Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand play took 1 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: Oct 11 18:29:22 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:22 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:22 volumio volumio[1383]: info: Oct 11 18:29:22 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:22 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:22 volumio volumio[1383]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": Unknown error 524 Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand status took 3 milliseconds Oct 11 18:29:22 volumio volumio[1383]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": Unknown error 524 Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand status took 2 milliseconds Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand clearerror took 2 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand clearerror took 1 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 11 18:29:22 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:22 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:22 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:22 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:22 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE","trackType":"qobuz"} Oct 11 18:29:22 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:22 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:22 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:22 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:22 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:22 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736161&hmac=lEJsoi39p8_wIw8L4vQLNSKGBsE","trackType":"qobuz"} Oct 11 18:29:22 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:22 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:22 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:22 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:22 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:22 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:22.511+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=1002 volume=100 Oct 11 18:29:22 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:22.511+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:22 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:22.512+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=1002 volume=100 Oct 11 18:29:22 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:22.512+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:22 volumio volumio[1383]: info: ------------------------------ 12ms Oct 11 18:29:22 volumio volumio[1383]: info: ------------------------------ 10ms Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioRandom Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::writePlayerControls Oct 11 18:29:23 volumio volumio[1383]: info: CoreStateMachine::setRandom true Oct 11 18:29:23 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:23 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:23 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:23 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:23.133+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=1614 volume=100 Oct 11 18:29:23 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:23.133+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioRandom Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::writePlayerControls Oct 11 18:29:23 volumio volumio[1383]: info: CoreStateMachine::setRandom false Oct 11 18:29:23 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:23 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:23 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:23 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:23 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:23.824+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=2252 volume=100 Oct 11 18:29:23 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:23.824+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:24 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:24 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 11 18:29:24 volumio volumio[1383]: info: CoreCommandRouter::volumioPlay Oct 11 18:29:24 volumio volumio[1383]: info: CoreStateMachine::play index undefined Oct 11 18:29:24 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 18:29:24 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:24 volumio volumio[1383]: info: CoreStateMachine::startPlaybackTimer Oct 11 18:29:24 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:24 volumio volumio[1383]: info: [1791732564649] ControllerQobuz::clearAddPlayTrack Oct 11 18:29:25 volumio volumio[1383]: info: getStreamUrl took 671 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand stop Oct 11 18:29:25 volumio volumio[1383]: info: Oct 11 18:29:25 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand stop took 8 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clear Oct 11 18:29:25 volumio volumio[1383]: info: Oct 11 18:29:25 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:25 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand status took 0 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand clear took 1 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA" Oct 11 18:29:25 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:25 volumio volumio[1383]: info: ------------------------------ 1ms Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:25 volumio volumio[1383]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 11 18:29:25 volumio volumio[1383]: info: ------------------------------ 1ms Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA" Oct 11 18:29:25 volumio volumio[1383]: info: Oct 11 18:29:25 volumio volumio[1383]: ---------------------------- MPD announces system playlist update Oct 11 18:29:25 volumio volumio[1383]: info: Ignoring MPD Status Update Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA" took 0 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand play Oct 11 18:29:25 volumio volumio[1383]: info: ------------------------------ 1ms Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand play took 1 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: Oct 11 18:29:25 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:25 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:25 volumio volumio[1383]: info: Oct 11 18:29:25 volumio volumio[1383]: ---------------------------- MPD announces state update: player Oct 11 18:29:25 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:25 volumio volumio[1383]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": Unknown error 524 Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand status took 1 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:25 volumio volumio[1383]: error: MPD returned error for command status: Failed to open "alsa" (alsa); Failed to open ALSA device "volumio": Unknown error 524 Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand status took 4 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand clearerror took 4 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:25 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:25 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:25 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","trackType":"qobuz"} Oct 11 18:29:25 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:25 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:25 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:25 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:25.818+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=1000 volume=100 Oct 11 18:29:25 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:25.818+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:25 volumio volumio[1383]: info: ------------------------------ 11ms Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand clearerror took 6 milliseconds Oct 11 18:29:25 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 11 18:29:25 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:25 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:25 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:25 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","trackType":"qobuz"} Oct 11 18:29:25 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:25 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:25 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:25 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:25 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:25 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:25.822+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=1000 volume=100 Oct 11 18:29:25 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:25.823+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:25 volumio volumio[1383]: info: ------------------------------ 14ms Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: Retrieving Cloud Streaming UI Oct 11 18:29:37 volumio volumio[1383]: info: Getting Tidal Cloud Configuration Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: Getting Qobuz Cloud Configuration Oct 11 18:29:37 volumio volumio[1383]: info: Asking plugin for UI Config Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: Getting Spotify Cloud Configuration Oct 11 18:29:37 volumio volumio[1383]: info: Asking plugin for UI Config Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: Saving Spotify Acccount Oct 11 18:29:37 volumio volumio[1383]: info: Got it Oct 11 18:29:37 volumio volumio[1383]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 11 18:29:37 volumio volumio[1383]: info: Got Tidal Cloud Configuration Oct 11 18:29:37 volumio volumio[1383]: info: Got it Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::volumioGetBrowseSources Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::volumioGetBrowseSources Oct 11 18:29:37 volumio volumio[1383]: info: CoreCommandRouter::volumioGetBrowseSources Oct 11 18:29:38 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 18:29:38 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 11 18:29:39 volumio ntpd[1170]: PROTO: 90.188.9.144 unlink local addr 192.168.1.18 -> Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand update Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:40 volumio volumio[1383]: info: Oct 11 18:29:40 volumio volumio[1383]: ---------------------------- MPD announces state update: update Oct 11 18:29:40 volumio volumio[1383]: info: sendMpdCommand update took 2 milliseconds Oct 11 18:29:40 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:40 volumio volumio[1383]: info: sendMpdCommand status took 1 milliseconds Oct 11 18:29:40 volumio volumio[1383]: info: sendMpdCommand status took 1 milliseconds Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:40 volumio volumio[1383]: info: Command Router : Notfying DB Updatetrue Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::Close All Modals sent Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:40 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 11 18:29:40 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:40 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:40 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:40 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","trackType":"qobuz"} Oct 11 18:29:40 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:40 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:40 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:40 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:40 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:40 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:40 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:40 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:40.300+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=15406 volume=100 Oct 11 18:29:40 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:40.300+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:40 volumio volumio[1383]: info: ------------------------------ 29ms Oct 11 18:29:42 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 18:29:43 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 18:29:44 volumio volumio[1383]: info: MPD Database updated - AlbumList cache refreshed Oct 11 18:29:44 volumio volumio[1383]: info: Oct 11 18:29:44 volumio volumio[1383]: ---------------------------- MPD announces state update: database Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:44 volumio volumio[1383]: info: Oct 11 18:29:44 volumio volumio[1383]: ---------------------------- MPD announces state update: update Oct 11 18:29:44 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:44 volumio volumio[1383]: info: ControllerMpd::getState Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand status Oct 11 18:29:44 volumio volumio[1383]: info: sendMpdCommand status took 43 milliseconds Oct 11 18:29:44 volumio volumio[1383]: info: sendMpdCommand status took 43 milliseconds Oct 11 18:29:44 volumio volumio[1383]: info: sendMpdCommand status took 43 milliseconds Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:44 volumio volumio[1383]: info: Command Router : Notfying DB Updatefalse Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::Close All Modals sent Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::parseState Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 18:29:44 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 18:29:44 volumio volumio[1383]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:44 volumio volumio[1383]: verbose: ControllerMpd::parseTrackInfo Oct 11 18:29:44 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:44 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:44 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","trackType":"qobuz"} Oct 11 18:29:44 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:44 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:44 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:44 volumio volumio[1383]: info: ControllerMpd::pushState Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::servicePushState Oct 11 18:29:44 volumio volumio[1383]: info: CorePlayQueue::getTrack 1 Oct 11 18:29:44 volumio volumio[1383]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":203,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=8837666&eid=442065577&fmt=7&profile=raw&app_id=539451548&cid=4651617&etsp=1791736164&hmac=1imXqMUvxTLGxEKtUwnfip4uEGA","trackType":"qobuz"} Oct 11 18:29:44 volumio volumio[1383]: verbose: CURRENT POSITION 1 Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::syncState stateService pause Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::syncState currentStatus stop Oct 11 18:29:44 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:44 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:44 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:44 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:44 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:44.705+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=20051 volume=100 Oct 11 18:29:44 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:44.705+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:44 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:44.705+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=20051 volume=100 Oct 11 18:29:44 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:44.706+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:44 volumio volumio[1383]: info: ------------------------------ 76ms Oct 11 18:29:44 volumio volumio[1383]: info: ------------------------------ 76ms Oct 11 18:29:44 volumio ntpd[1170]: PROTO: 87.103.245.205 unlink local addr 192.168.1.18 -> Oct 11 18:29:45 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:45 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:45 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:45 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:45 volumio volumio[1383]: info: Executing endpoint metavolumio Oct 11 18:29:45 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 11 18:29:48 volumio volumio[1383]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 11 18:29:48 volumio volumio[1383]: info: Preparing to save Alsa Options, stopping services first Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioPause Oct 11 18:29:48 volumio volumio[1383]: info: CoreStateMachine::pause Oct 11 18:29:48 volumio volumio[1383]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"HDMI 1 Out"},"i2s":true,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: Enabling I2S DAC: Adafruit MAX98357 Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio sudo[8680]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 11 18:29:48 volumio sudo[8680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8680]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8684]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r rotary-encoderpin_a=17pin_b=27relative_axis=truesteps-per-period=1 Oct 11 18:29:48 volumio sudo[8684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8684]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: * Overlay 'rotary-encoderpin_a=17pin_b=27relative_axis=truesteps-per-period=1' is not loaded Oct 11 18:29:48 volumio volumio[1383]: error: Cannot remove overlay Oct 11 18:29:48 volumio sudo[8692]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r gpio-keygpio=22active_low=truegpio_pull=upkeycode=20 Oct 11 18:29:48 volumio sudo[8692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8692]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: * Overlay 'gpio-keygpio=22active_low=truegpio_pull=upkeycode=20' is not loaded Oct 11 18:29:48 volumio volumio[1383]: error: Cannot remove overlay Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio sudo[8699]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay max98357a Oct 11 18:29:48 volumio sudo[8699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8699]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /axi/pcie@1000120000/rp1/i2s@a0000/status Oct 11 18:29:48 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc@107c000000/sound/compatible Oct 11 18:29:48 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc@107c000000/sound/simple-audio-card,format Oct 11 18:29:48 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc@107c000000/sound/simple-audio-card,name Oct 11 18:29:48 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc@107c000000/sound/status Oct 11 18:29:48 volumio volumio[1383]: warn: Unable to locate the device HDMI 1 Out a reboot may be required. Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: Device 2 does not have any Mixer Control Available Oct 11 18:29:48 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio vtcs[7254]: [2026-10-11 18:29:48.316] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Oct 11 18:29:48 volumio vtcs[7254]: [2026-10-11 18:29:48.317] [tisoc] [error] [SpkconServer.cpp:383] recv error. client fd=8 errorno=104 error=Connection reset by peer Oct 11 18:29:48 volumio vtcs[7254]: [2026-10-11 18:29:48.317] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Oct 11 18:29:48 volumio sudo[8722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 11 18:29:48 volumio volumio[1383]: info: Updating Volume Controller Parameters: Device: 2 Name: Adafruit MAX98357 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 11 18:29:48 volumio volumio[1383]: info: Disabling external Volume Control Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Oct 11 18:29:48 volumio volumio[1383]: info: CoreStateMachine::pushState Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioPushState Oct 11 18:29:48 volumio volumio[1383]: info: MRS: Pushing multiroomSync output update for this device Oct 11 18:29:48 volumio volumio[1383]: info: MRS: Pushing multiroomSync output Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:48.340+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" state=STATUS_PAUSED positionMs=23354 volume=100 Oct 11 18:29:48 volumio volumio5-onboarding[1742]: time=2026-10-11T18:29:48.340+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.117:43710 @ 0x1c00660" id=qobuz://song/48098084 title="Baby Be Mine" Oct 11 18:29:48 volumio volumio[1383]: info: Preparing to generate the ALSA configuration file Oct 11 18:29:48 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 11 18:29:48 volumio systemd[1]: vtcs.service: Killing process 7260 (vtcs) with signal SIGKILL. Oct 11 18:29:48 volumio systemd[1]: vtcs.service: Killing process 7261 (vtcs) with signal SIGKILL. Oct 11 18:29:48 volumio systemd[1]: vtcs.service: Killing process 7262 (vtcs) with signal SIGKILL. Oct 11 18:29:48 volumio systemd[1]: vtcs.service: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 11 18:29:48 volumio sudo[8722]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 11 18:29:48 volumio volumio[1383]: info: The plugin glass has an ALSA contribution file Glass.postGlass.5.conf Oct 11 18:29:48 volumio volumio[1383]: info: Reading ALSA contributions from plugins. Oct 11 18:29:48 volumio sudo[8737]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: info: I2S Param [object Object] successfully enabled Oct 11 18:29:48 volumio sudo[8749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 11 18:29:48 volumio sudo[8749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8749]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 11 18:29:48 volumio sudo[8757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 18:29:48 volumio volumio[1383]: info: Getting Alsa Cards List without I2S DAC Oct 11 18:29:48 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 11 18:29:48 volumio qobuz-connect[7222]: 20261011 18:29:48.497 [7222.7222] INFO SampleApp: Stopping Local configuration server Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 18:29:48 volumio volumio[1383]: info: Asound.conf file written Oct 11 18:29:48 volumio sudo[8771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 11 18:29:48 volumio sudo[8771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8771]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting MPD Oct 11 18:29:48 volumio sudo[8777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting Shairport Sync Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio sudo[8777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8777]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 18:29:48 volumio sudo[8779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 18:29:48 volumio volumio[1383]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting MPD Oct 11 18:29:48 volumio sudo[8789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting Shairport Sync Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio sudo[8792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 18:29:48 volumio sudo[8792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 11 18:29:48 volumio systemd[1]: mpd.service: Consumed 12.248s CPU time. Oct 11 18:29:48 volumio sudo[8792]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 11 18:29:48 volumio sudo[8794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 18:29:48 volumio sudo[8794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 18:29:48 volumio volumio[1383]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 11 18:29:48 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio sudo[8805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio sudo[8809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 11 18:29:48 volumio sudo[8812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 11 18:29:48 volumio sudo[8821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 11 18:29:48 volumio volumio[1383]: info: MPD Permissions set Oct 11 18:29:48 volumio volumio[1383]: info: MPD Permissions set Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio sudo[8827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 11 18:29:48 volumio sudo[8827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio sudo[8821]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8789]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8805]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 11 18:29:48 volumio sudo[8835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 11 18:29:48 volumio sudo[8827]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: Starting Shairport Sync Oct 11 18:29:48 volumio volumio[1383]: info: Starting Shairport Sync Oct 11 18:29:48 volumio sudo[8846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 18:29:48 volumio sudo[8846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 11 18:29:48 volumio sudo[8843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: Preparing to generate the ALSA configuration file Oct 11 18:29:48 volumio sudo[8849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 18:29:48 volumio sudo[8849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio volumio[1383]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 11 18:29:48 volumio volumio[1383]: info: The plugin glass has an ALSA contribution file Glass.postGlass.5.conf Oct 11 18:29:48 volumio volumio[1383]: info: Reading ALSA contributions from plugins. Oct 11 18:29:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 11 18:29:48 volumio volumio[1383]: info: Asound.conf file written Oct 11 18:29:48 volumio sudo[8809]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 11 18:29:48 volumio sudo[8857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8812]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8857]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting MPD Oct 11 18:29:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 11 18:29:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:48 volumio systemd[1]: shairport-sync.service: Consumed 1.852s CPU time. Oct 11 18:29:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:48 volumio sudo[8854]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 18:29:48 volumio sudo[8854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 11 18:29:48 volumio sudo[8849]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8846]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio sudo[8854]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting Shairport Sync Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio sudo[8867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 18:29:48 volumio sudo[8867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 18:29:48 volumio sudo[8873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8867]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 18:29:48 volumio volumio[1383]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:48 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 11 18:29:48 volumio volumio[1383]: info: Preparing to generate the ALSA configuration file Oct 11 18:29:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 11 18:29:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 11 18:29:48 volumio sudo[8894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio sudo[8898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:48 volumio sudo[8898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 11 18:29:48 volumio volumio[1383]: info: The plugin glass has an ALSA contribution file Glass.postGlass.5.conf Oct 11 18:29:48 volumio volumio[1383]: info: Reading ALSA contributions from plugins. Oct 11 18:29:48 volumio volumio[1383]: info: MPD Permissions set Oct 11 18:29:48 volumio volumio[1383]: info: Shairport-Sync Started Oct 11 18:29:48 volumio volumio[1383]: info: Shairport-Sync Started Oct 11 18:29:48 volumio volumio[1383]: (node:1383) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Oct 11 18:29:48 volumio volumio[1383]: (Use `node --trace-warnings ...` to show where the warning was created) Oct 11 18:29:48 volumio volumio[1383]: (node:1383) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Oct 11 18:29:48 volumio volumio[1383]: (node:1383) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Oct 11 18:29:48 volumio volumio[1383]: (node:1383) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Oct 11 18:29:48 volumio volumio[1383]: (node:1383) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Oct 11 18:29:48 volumio sudo[8905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 11 18:29:48 volumio sudo[8905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 11 18:29:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:48 volumio volumio[1383]: info: Starting Shairport Sync Oct 11 18:29:48 volumio sudo[8905]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:48 volumio volumio[1383]: info: Asound.conf file unchanged, so no further update is needed Oct 11 18:29:48 volumio volumio[1383]: info: Output device has changed, restarting MPD Oct 11 18:29:49 volumio sudo[8914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 18:29:49 volumio sudo[8914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio sudo[8894]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 11 18:29:49 volumio sudo[8915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio volumio[1383]: info: Output device has changed, restarting Shairport Sync Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:49 volumio sudo[8918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 18:29:49 volumio sudo[8918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio sudo[8898]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8918]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 18:29:49 volumio sudo[8922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio sudo[8909]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 18:29:49 volumio sudo[8909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 11 18:29:49 volumio sudo[8909]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 18:29:49 volumio volumio[1383]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:49 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 11 18:29:49 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:49 volumio sudo[8935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:49 volumio sudo[8935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 11 18:29:49 volumio sudo[8938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 11 18:29:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 11 18:29:49 volumio sudo[8938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 11 18:29:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 11 18:29:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 11 18:29:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 11 18:29:49 volumio qobuz-connect[7222]: 20261011 18:29:49.106 [7222.7222] INFO SampleApp: shat down connection on UNIX socket Oct 11 18:29:49 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:49 volumio sudo[8914]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Oct 11 18:29:49 volumio volumio[1383]: info: MPD Permissions set Oct 11 18:29:49 volumio volumio[1383]: info: Shairport-Sync Started Oct 11 18:29:49 volumio volumio[1383]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Oct 11 18:29:49 volumio volumio[1383]: info: QobuzConnect: setDeactiveState invoked Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::volumioGetState Oct 11 18:29:49 volumio sudo[8948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Oct 11 18:29:49 volumio sudo[8948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 18:29:49 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Oct 11 18:29:49 volumio sudo[8915]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8757]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8835]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8945]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 18:29:49 volumio sudo[8843]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 11 18:29:49 volumio sudo[8945]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: info: Starting Shairport Sync Oct 11 18:29:49 volumio sudo[8948]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8935]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: info: Executing endpoint qc_getconfig Oct 11 18:29:49 volumio volumio[1383]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Oct 11 18:29:49 volumio sudo[8938]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 18:29:49 volumio sudo[8974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio sudo[8972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Oct 11 18:29:49 volumio sudo[8972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 11 18:29:49 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.217 [8966.8966] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Oct 11 18:29:49 volumio volumio[1383]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Oct 11 18:29:49 volumio volumio[1383]: info: QobuzConnect: QOBUZ Connect daemon connected Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.218 [8966.8966] INFO VolumeManager: [0x1119db8]: Setting new playback volume: 75 Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.218 [8966.8966] INFO VolumeManager: [0x1119db8]: Setting new mute state: 0 Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.218 [8966.8966] INFO AudioStreamManager: [0x1119b10]: Setting new audio download buffer size: 1048576 Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.218 [8966.8966] INFO QobuzConnect: [0x111a680]: Client initialized! Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.218 [8966.8966] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.225 [8966.8966] INFO LocalConfigManager: [0x1119838]: Starting Local Configuration server Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.225 [8966.8966] INFO SampleApp: Starting Local configuration server Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.226 [8966.8966] INFO SampleApp: Connected to UNIX socket client 0x1104818 Oct 11 18:29:49 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:49 volumio sudo[8974]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Oct 11 18:29:49 volumio qobuz-connect[8966]: 20261011 18:29:49.254 [8966.8966] INFO SampleApp: Stopping Local configuration server Oct 11 18:29:49 volumio volumio[1383]: info: Shairport-Sync Started Oct 11 18:29:49 volumio mpd[8971]: 2026-10-11T18:29:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 11 18:29:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 11 18:29:49 volumio sudo[8922]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8873]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[8794]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:49 volumio sudo[8779]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: error: MPD error: The expression evaluated to a falsy value: Oct 11 18:29:49 volumio volumio[1383]: assert.ok(self.idling) Oct 11 18:29:49 volumio volumio[1383]: error: The expression evaluated to a falsy value: Oct 11 18:29:49 volumio volumio[1383]: assert.ok(self.idling) Oct 11 18:29:49 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:49 volumio volumio[1383]: error: updateQueue error: null Oct 11 18:29:49 volumio volumio[1383]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Oct 11 18:29:49 volumio volumio[1383]: info: PLUGIN onReboot : networkfs Oct 11 18:29:49 volumio volumio[1383]: info: PLUGIN onReboot : touch_display Oct 11 18:29:49 volumio sudo[9005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Oct 11 18:29:49 volumio sudo[9005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio systemd[1]: Stopping volumio-kiosk.service - Volumio Kiosk... Oct 11 18:29:49 volumio startx[2054]: xinit: connection to X server lost Oct 11 18:29:49 volumio startx[2054]: Oct 11 18:29:49 volumio sudo[9011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reboot Oct 11 18:29:49 volumio sudo[9011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:49 volumio systemd-logind[974]: The system will reboot now! Oct 11 18:29:49 volumio systemd-logind[974]: System is rebooting. Oct 11 18:29:49 volumio sudo[8972]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio sudo[9011]: pam_unix(sudo:session): session closed for user root Oct 11 18:29:49 volumio volumio[1383]: error: QobuzConnect: could not execute /bin/systemctl to restart qobuz connect process. Reason: Job for qobuz-connect.service canceled. Oct 11 18:29:49 volumio volumio[1383]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 18:29:49 volumio volumio[1383]: [UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "undefined".] { Oct 11 18:29:49 volumio volumio[1383]: code: 'ERR_UNHANDLED_REJECTION' Oct 11 18:29:49 volumio volumio[1383]: } Oct 11 18:29:49 volumio volumio[1383]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 18:29:49 volumio systemd[1]: Removed slice system-modprobe.slice - Slice /system/modprobe. Oct 11 18:29:49 volumio systemd[1]: Stopped target bluetooth.target - Bluetooth Support. Oct 11 18:29:49 volumio systemd[1]: Stopped target graphical.target - Graphical Interface. Oct 11 18:29:49 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Oct 11 18:29:49 volumio systemd[1]: Stopped target rpc_pipefs.target. Oct 11 18:29:49 volumio systemd[1]: Stopped target rpcbind.target - RPC Port Mapper. Oct 11 18:29:49 volumio systemd[1]: Stopped target timers.target - Timer Units. Oct 11 18:29:49 volumio systemd[1]: apt-daily-upgrade.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Oct 11 18:29:49 volumio systemd[1]: apt-daily.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped apt-daily.timer - Daily apt download activities. Oct 11 18:29:49 volumio systemd[1]: dpkg-db-backup.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped dpkg-db-backup.timer - Daily dpkg database backup timer. Oct 11 18:29:49 volumio systemd[1]: e2scrub_all.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Oct 11 18:29:49 volumio systemd[1]: fstrim.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped fstrim.timer - Discard unused blocks once a week. Oct 11 18:29:49 volumio systemd[1]: man-db.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped man-db.timer - Daily man-db regeneration. Oct 11 18:29:49 volumio systemd[1]: ntpsec-rotate-stats.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Oct 11 18:29:49 volumio systemd[1]: setdatetime-helper.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Oct 11 18:29:49 volumio systemd[1]: systemd-tmpfiles-clean.timer: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Oct 11 18:29:49 volumio systemd[1]: systemd-rfkill.socket: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Closed systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. Oct 11 18:29:49 volumio systemd[1]: Unmounting run-rpc_pipefs.mount - RPC Pipe File System... Oct 11 18:29:49 volumio bluealsa[1126]: (../../../gio/gdbusobjectmanagerserver.c:1168):unexport_all: runtime check failed: (manager->priv->manager_reg_id > 0) Oct 11 18:29:49 volumio bluetoothd[946]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/1 Oct 11 18:29:49 volumio bluetoothd[946]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/2 Oct 11 18:29:49 volumio bluetoothd[946]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/source/2 Oct 11 18:29:49 volumio systemd[1]: Stopping bluealsa.service - BlueALSA service... Oct 11 18:29:49 volumio bluetoothd[946]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/sink/1 Oct 11 18:29:49 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 11 18:29:49 volumio systemd[1]: Stopping roonbridge.service - Roon Bridge... Oct 11 18:29:49 volumio systemd[1]: rpi-display-backlight.service - Turns off Raspberry Pi display backlight on shutdown/reboot was skipped because of an unmet condition check (ConditionPathIsDirectory=/proc/device-tree/rpi_backlight). Oct 11 18:29:49 volumio autossh[7497]: received signal to exit (15) Oct 11 18:29:49 volumio systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Oct 11 18:29:49 volumio systemd[1]: Stopping systemd-random-seed.service - Load/Save Random Seed... Oct 11 18:29:49 volumio systemd[1]: Stopping upower.service - Daemon for power management... Oct 11 18:29:49 volumio systemd[1]: Stopping volumio5-onboarding.service - Volumio5 Onboarding Server... Oct 11 18:29:49 volumio systemd[1]: Stopping volumiobt.service - Volumio Bluetooth Module... Oct 11 18:29:49 volumio systemd[1]: bluealsa.service: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped bluealsa.service - BlueALSA service. Oct 11 18:29:49 volumio systemd[1]: upower.service: Deactivated successfully. Oct 11 18:29:49 volumio systemd[1]: Stopped upower.service - Daemon for power management. Oct 11 18:29:49 volumio systemd[1]: volumio5-onboarding.service: Deactivated successfully. Oct 11 18:29:49 volumio volumiobt[9035]: INFO [BTSTART] Disconnecting all Bluetooth devices... Oct 11 18:29:49 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 11 18:29:49 volumio systemd[1]: sshtunnel.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Oct 11 18:29:50 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 11 18:29:50 volumio systemd[1]: run-rpc_pipefs.mount: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Unmounted run-rpc_pipefs.mount - RPC Pipe File System. Oct 11 18:29:50 volumio systemd[1]: systemd-random-seed.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped systemd-random-seed.service - Load/Save Random Seed. Oct 11 18:29:50 volumio bluetoothd[946]: Adv Monitor app :1.395 disconnected from D-Bus Oct 11 18:29:50 volumio systemd[1]: roonbridge.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped roonbridge.service - Roon Bridge. Oct 11 18:29:50 volumio systemd[1]: roonbridge.service: Consumed 8.338s CPU time. Oct 11 18:29:50 volumio volumiobt[9045]: Attempting to disconnect from 98:F6:21:32:2F:0C Oct 11 18:29:50 volumio volumiobt[9045]: [NEW] Media /org/bluez/hci0 Oct 11 18:29:50 volumio volumiobt[9045]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio volumiobt[9045]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio volumiobt[9045]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio volumiobt[9045]: Disconnection successful Oct 11 18:29:50 volumio bluetoothd[946]: Path / reserved for Adv Monitor app :1.396 Oct 11 18:29:50 volumio bluetoothd[946]: Adv Monitor app :1.396 disconnected from D-Bus Oct 11 18:29:50 volumio volumiobt[9046]: INFO [BTSTART] Disconnected device: 98:F6:21:32:2F:0C Oct 11 18:29:50 volumio volumiobt[9047]: INFO [BTSTART] Unregistering Bluetooth agent... Oct 11 18:29:50 volumio volumiobt[9048]: No agent is registered Oct 11 18:29:50 volumio volumiobt[9048]: [NEW] Media /org/bluez/hci0 Oct 11 18:29:50 volumio volumiobt[9048]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio volumiobt[9048]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio volumiobt[9048]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Oct 11 18:29:50 volumio bluetoothd[946]: Adv Monitor app :1.397 disconnected from D-Bus Oct 11 18:29:50 volumio volumiobt[9049]: INFO [BTSTART] Stopping bluealsa-aplay (if any)... Oct 11 18:29:50 volumio volumiobt[9051]: INFO [BTSTART] Stopping A2DP agent (a2dp-agent)... Oct 11 18:29:50 volumio startx[2054]: waiting for X server to shut down Oct 11 18:29:50 volumio startx[2055]: (II) Server terminated successfully (0). Closing log file. Oct 11 18:29:50 volumio systemd[1]: volumiobt.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Oct 11 18:29:50 volumio systemd[1]: Stopped target multi-user.target - Multi-User System. Oct 11 18:29:50 volumio systemd[1]: Stopped target getty.target - Login Prompts. Oct 11 18:29:50 volumio bluetoothd[946]: Terminating Oct 11 18:29:50 volumio systemd[1]: Stopping bluetooth.service - Bluetooth service... Oct 11 18:29:50 volumio bluetoothd[946]: Destroy Adv Monitor Manager Oct 11 18:29:50 volumio bluetoothd[946]: Battery Provider Manager destroyed Oct 11 18:29:50 volumio bluetoothd[946]: Stopping SDP server Oct 11 18:29:50 volumio bluetoothd[946]: Exit Oct 11 18:29:50 volumio systemd[1]: Stopping cpufrequtils.service - LSB: set CPUFreq kernel parameters... Oct 11 18:29:50 volumio ntpd[1170]: ERR: ntpd exiting on signal 15 (Terminated) Oct 11 18:29:50 volumio systemd[1]: glamor-test.service: Deactivated successfully. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 195.122.253.38 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopped glamor-test.service - Check for glamor. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 162.159.200.1 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping ifplugd.service - LSB: Brings up/down network automatically... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 92.241.18.6 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping ntpsec.service - Network Time Service... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 92.255.126.1 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: plymouth-quit.service: Deactivated successfully. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 92.241.18.100 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopped plymouth-quit.service - Terminate Plymouth Boot Screen. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 92.255.126.22 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: rp1-test.service: Deactivated successfully. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 185.211.244.47 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopped rp1-test.service - Check for RP1 displays for Xorg. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 46.147.193.187 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: rpi-eeprom-update.service: Deactivated successfully. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 217.170.87.229 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopped rpi-eeprom-update.service - Check for Raspberry Pi EEPROM updates. Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 45.141.102.99 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping serial-getty@ttyAMA10.service - Serial Getty on ttyAMA10... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 31.135.73.5 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 195.218.227.230 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping smbd.service - Samba SMB Daemon... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 87.249.44.53 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping ssh.service - OpenBSD Secure Shell server... Oct 11 18:29:50 volumio ntpd[1170]: PROTO: 185.119.57.152 unlink local addr 192.168.1.18 -> Oct 11 18:29:50 volumio systemd[1]: Stopping systemd-logind.service - User Login Management... Oct 11 18:29:50 volumio sshd[1217]: Received signal 15; terminating. Oct 11 18:29:50 volumio systemd[1]: Stopping triggerhappy.service - triggerhappy global hotkey daemon... Oct 11 18:29:50 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Oct 11 18:29:50 volumio systemd[1]: Stopping volumio-ipchange.service - Volumio IP Change Monitor... Oct 11 18:29:50 volumio systemd[1]: Stopping volumio-remote-updater.service - Volumio Remote OTA Updater... Oct 11 18:29:50 volumio systemd[1]: welcome.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Oct 11 18:29:50 volumio systemd[1]: bluetooth.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped bluetooth.service - Bluetooth service. Oct 11 18:29:50 volumio systemd[1]: volumio-remote-updater.service: Deactivated successfully. Oct 11 18:29:50 volumio sudo[9062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-11 18:28' Oct 11 18:29:50 volumio sudo[9062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 11 18:29:50 volumio systemd[1]: Stopped volumio-remote-updater.service - Volumio Remote OTA Updater. Oct 11 18:29:50 volumio systemd[1]: ntpsec.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped ntpsec.service - Network Time Service. Oct 11 18:29:50 volumio systemd[1]: volumio-ipchange.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped volumio-ipchange.service - Volumio IP Change Monitor. Oct 11 18:29:50 volumio systemd[1]: ssh.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped ssh.service - OpenBSD Secure Shell server. Oct 11 18:29:50 volumio systemd[1]: serial-getty@ttyAMA10.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped serial-getty@ttyAMA10.service - Serial Getty on ttyAMA10. Oct 11 18:29:50 volumio systemd[1]: smbd.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped smbd.service - Samba SMB Daemon. Oct 11 18:29:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 11 18:29:50 volumio systemd[1]: Removed slice system-serial\x2dgetty.slice - Slice /system/serial-getty. Oct 11 18:29:50 volumio systemd[1]: Stopped target sound.target - Sound Card. Oct 11 18:29:50 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Oct 11 18:29:50 volumio avahi-daemon[945]: Got SIGTERM, quitting. Oct 11 18:29:50 volumio systemd[1]: plymouth-quit-wait.service: Deactivated successfully. Oct 11 18:29:50 volumio avahi-daemon[945]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.18. Oct 11 18:29:50 volumio systemd[1]: Stopped plymouth-quit-wait.service - Hold until boot process finishes up. Oct 11 18:29:50 volumio avahi-daemon[945]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Oct 11 18:29:50 volumio systemd[1]: rc-local.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped rc-local.service - /etc/rc.local Compatibility. Oct 11 18:29:50 volumio systemd[1]: Stopping systemd-user-sessions.service - Permit User Sessions... Oct 11 18:29:50 volumio systemd[1]: Stopping winbind.service - Samba Winbind Daemon... Oct 11 18:29:50 volumio winbindd[1587]: [2026/10/11 18:29:50.169280, 0] ../../source3/winbindd/winbindd_dual.c:1950(winbindd_sig_term_handler) Oct 11 18:29:50 volumio systemd[1]: systemd-logind.service: Deactivated successfully. Oct 11 18:29:50 volumio winbindd[1587]: Got sig[15] terminate (is_parent=1) Oct 11 18:29:50 volumio systemd[1]: Stopped systemd-logind.service - User Login Management. Oct 11 18:29:50 volumio winbindd[1593]: [2026/10/11 18:29:50.169335, 0] ../../source3/winbindd/winbindd_dual.c:1950(winbindd_sig_term_handler) Oct 11 18:29:50 volumio winbindd[1593]: Got sig[15] terminate (is_parent=0) Oct 11 18:29:50 volumio ifplugd(eth0)[1215]: Exiting. Oct 11 18:29:50 volumio systemd[1]: winbind.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped winbind.service - Samba Winbind Daemon. Oct 11 18:29:50 volumio avahi-daemon[945]: avahi-daemon 0.8 exiting. Oct 11 18:29:50 volumio systemd[1]: cpufrequtils.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped cpufrequtils.service - LSB: set CPUFreq kernel parameters. Oct 11 18:29:50 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Oct 11 18:29:50 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Oct 11 18:29:50 volumio systemd[1]: Stopping loadcpufreq.service - LSB: Load kernel modules needed to enable cpufreq scaling... Oct 11 18:29:50 volumio nmbd[1274]: [2026/10/11 18:29:50.179953, 0] ../../source3/nmbd/nmbd.c:59(terminate) Oct 11 18:29:50 volumio nmbd[1274]: Got SIGTERM: going down... Oct 11 18:29:50 volumio systemd[1]: Stopping nmbd.service - Samba NMB Daemon... 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"