May 26 07:57:22 volumio kernel: usb 1-1: USB disconnect, device number 2 May 26 07:57:22 volumio volumio[1774]: info: May 26 07:57:22 volumio volumio[1774]: ---------------------------- MPD announces state update: player May 26 07:57:22 volumio volumio[1774]: info: ControllerMpd::getState May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand status May 26 07:57:22 volumio volumio[1774]: info: May 26 07:57:22 volumio volumio[1774]: ---------------------------- MPD announces state update: player May 26 07:57:22 volumio volumio[1774]: info: ControllerMpd::getState May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand status May 26 07:57:22 volumio volumio[1774]: error: MPD returned error for command status: Failed to open audio output May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand status took 6 milliseconds May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::parseState May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 07:57:22 volumio volumio[1774]: error: MPD returned error for command status: Failed to open audio output May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand status took 8 milliseconds May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand clearerror took 3 milliseconds May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand playlistinfo took 3 milliseconds May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::parseState May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::parseTrackInfo May 26 07:57:22 volumio volumio[1774]: info: ControllerMpd::pushState May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio[1774]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":223210,"duration":285,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1715 Kbps","isStreaming":false,"title":"file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","trackType":"qobuz"} May 26 07:57:22 volumio volumio[1774]: verbose: CURRENT POSITION 1 May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::syncState stateService pause May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::syncState currentStatus play May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio5-onboarding[1548]: time=2026-05-26T07:57:22.690+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=223008 volume=46 May 26 07:57:22 volumio volumio5-onboarding[1548]: time=2026-05-26T07:57:22.690+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id=qobuz://song/203578464 title="Did you know that there's a tunnel under Ocean Blvd" May 26 07:57:22 volumio volumio[1774]: info: ------------------------------ 15ms May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand clearerror took 9 milliseconds May 26 07:57:22 volumio volumio[1774]: info: sendMpdCommand playlistinfo took 8 milliseconds May 26 07:57:22 volumio volumio[1774]: verbose: ControllerMpd::parseTrackInfo May 26 07:57:22 volumio volumio[1774]: info: ControllerMpd::pushState May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio[1774]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":223210,"duration":285,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1715 Kbps","isStreaming":false,"title":"file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","trackType":"qobuz"} May 26 07:57:22 volumio volumio[1774]: verbose: CURRENT POSITION 1 May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::syncState stateService pause May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::syncState currentStatus play May 26 07:57:22 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:57:22 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:57:22 volumio volumio5-onboarding[1548]: time=2026-05-26T07:57:22.698+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=223008 volume=46 May 26 07:57:22 volumio volumio5-onboarding[1548]: time=2026-05-26T07:57:22.698+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id=qobuz://song/203578464 title="Did you know that there's a tunnel under Ocean Blvd" May 26 07:57:22 volumio volumio[1774]: info: ------------------------------ 22ms May 26 07:57:22 volumio volumio[1774]: info: May 26 07:57:22 volumio volumio[1774]: ---------------------------- USB Audio Device Detached May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 26 07:57:22 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: raat , onStop May 26 07:58:19 volumio volumio[1774]: info: CorePlayQueue::getTrack 1 May 26 07:58:19 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:19 volumio volumio[1774]: info: Prefetching next song May 26 07:58:19 volumio volumio[1774]: info: [1779757099559] ControllerQobuz::prefetch May 26 07:58:20 volumio volumio[1774]: info: getStreamUrl took 772 milliseconds May 26 07:58:20 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand load "https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578465&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760700&hmac=JcZuXPdOdmWcnEUHAZEu973J0fQ" May 26 07:58:21 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578465&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760700&hmac=JcZuXPdOdmWcnEUHAZEu973J0fQ" May 26 07:58:21 volumio volumio[1774]: info: May 26 07:58:21 volumio volumio[1774]: ---------------------------- MPD announces system playlist update May 26 07:58:21 volumio volumio[1774]: info: Ignoring MPD Status Update May 26 07:58:21 volumio volumio[1774]: info: sendMpdCommand add "https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578465&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760700&hmac=JcZuXPdOdmWcnEUHAZEu973J0fQ" took 0 milliseconds May 26 07:58:21 volumio volumio[1774]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 07:58:21 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand consume 1 May 26 07:58:21 volumio volumio[1774]: info: May 26 07:58:21 volumio volumio[1774]: ---------------------------- MPD announces system playlist update May 26 07:58:21 volumio volumio[1774]: info: Ignoring MPD Status Update May 26 07:58:21 volumio volumio[1774]: info: ------------------------------ 1ms May 26 07:58:21 volumio volumio[1774]: info: sendMpdCommand consume 1 took 1 milliseconds May 26 07:58:21 volumio volumio[1774]: info: ------------------------------ 0ms May 26 07:58:24 volumio volumio[1774]: info: CoreStateMachine::startPlaybackTimer May 26 07:58:24 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:24 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:24 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:24 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 07:58:24 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:24 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:24 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:24 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:24.546+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=251 volume=46 May 26 07:58:24 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:24.547+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id=qobuz://song/203578465 title=Sweet May 26 07:58:41 volumio kernel: usb 1-1: new high-speed USB device number 3 using xhci-hcd May 26 07:58:41 volumio kernel: usb 1-1: New USB device found, idVendor=16d0, idProduct=071a, bcdDevice= 1.97 May 26 07:58:41 volumio kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 26 07:58:41 volumio kernel: usb 1-1: Product: Combo384 Amanero May 26 07:58:41 volumio kernel: usb 1-1: Manufacturer: Amanero Technologies May 26 07:58:41 volumio kernel: usb 1-1: SerialNumber: 413-001 May 26 07:58:42 volumio mtp-probe[5229]: checking bus 1, device 3: "/sys/devices/platform/axi/1000120000.pcie/1f00200000.usb/xhci-hcd.0/usb1/1-1" May 26 07:58:42 volumio mtp-probe[5229]: bus: 1, device: 3 was not an MTP device May 26 07:58:42 volumio (udev-worker)[5228]: controlC5: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 5' failed with exit code 99. May 26 07:58:42 volumio volumio[1774]: info: May 26 07:58:42 volumio volumio[1774]: ---------------------------- USB Audio Device Attached May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::Close All Modals sent May 26 07:58:42 volumio volumio[1774]: info: Preparing to save Alsa Options, stopping services first May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioPause May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::pause May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::stPlaybackTimer May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::servicePause May 26 07:58:42 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::servicePause May 26 07:58:42 volumio volumio[1774]: info: [1779757122062] ControllerQobuz::pause May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 07:58:42 volumio volumio[1774]: info: ControllerMpd::pause May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand pause May 26 07:58:42 volumio volumio[1774]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Combo384 Amanero","alsacard":"Amanero"},"i2s":false} May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 26 07:58:42 volumio volumio[1774]: info: Setting mixer PCM for card Combo384 Amanero May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio vtcs[2795]: [2026-05-26 07:58:42.088] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 26 07:58:42 volumio vtcs[2795]: [2026-05-26 07:58:42.088] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 26 07:58:42 volumio sudo[5251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 26 07:58:42 volumio volumio[1774]: info: Updating Volume Controller Parameters: Device: 5 Name: Combo384 Amanero Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 26 07:58:42 volumio volumio[1774]: info: Disabling external Volume Control May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 07:58:42 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... May 26 07:58:42 volumio systemd[1]: vtcs.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. May 26 07:58:42 volumio volumio[1774]: info: Preparing to generate the ALSA configuration file May 26 07:58:42 volumio sudo[5251]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio mtp-probe[5259]: checking bus 1, device 3: "/sys/devices/platform/axi/1000120000.pcie/1f00200000.usb/xhci-hcd.0/usb1/1-1" May 26 07:58:42 volumio mtp-probe[5259]: bus: 1, device: 3 was not an MTP device May 26 07:58:42 volumio sudo[5258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: May 26 07:58:42 volumio volumio[1774]: ---------------------------- MPD announces state update: player May 26 07:58:42 volumio volumio[1774]: info: sendMpdCommand pause took 75 milliseconds May 26 07:58:42 volumio volumio[1774]: info: ControllerMpd::getState May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand status May 26 07:58:42 volumio volumio[1774]: info: May 26 07:58:42 volumio volumio[1774]: ---------------------------- MPD announces state update: player May 26 07:58:42 volumio volumio[1774]: info: ControllerMpd::getState May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand status May 26 07:58:42 volumio volumio[1774]: info: sendMpdCommand status took 11 milliseconds May 26 07:58:42 volumio volumio[1774]: info: sendMpdCommand status took 10 milliseconds May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::parseState May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::parseState May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 07:58:42 volumio volumio[1774]: info: sendMpdCommand playlistinfo took 3 milliseconds May 26 07:58:42 volumio volumio[1774]: info: sendMpdCommand playlistinfo took 3 milliseconds May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::parseTrackInfo May 26 07:58:42 volumio volumio[1774]: verbose: ControllerMpd::parseTrackInfo May 26 07:58:42 volumio volumio[1774]: info: ControllerMpd::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:58:42 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:42 volumio volumio[1774]: verbose: STATE SERVICE {"status":"play","position":0,"seek":224220,"duration":285,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1850 Kbps","isStreaming":false,"title":"file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","trackType":"qobuz"} May 26 07:58:42 volumio volumio[1774]: verbose: CURRENT POSITION 2 May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::syncState stateService play May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::syncState currentStatus pause May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:42 volumio sudo[5267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 26 07:58:42 volumio sudo[5267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5258]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio[1774]: info: ControllerMpd::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:58:42 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:42 volumio volumio[1774]: verbose: STATE SERVICE {"status":"play","position":0,"seek":224220,"duration":285,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1850 Kbps","isStreaming":false,"title":"file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8","trackType":"qobuz"} May 26 07:58:42 volumio volumio[1774]: verbose: CURRENT POSITION 2 May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::syncState stateService play May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::syncState currentStatus play May 26 07:58:42 volumio volumio[1774]: info: Received an update from plugin. extracting info from payload May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id="https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" title="file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id=qobuz://song/203578463 title="The Grants" May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.162+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id="https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" title="file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" May 26 07:58:42 volumio volumio[1774]: info: ------------------------------ 25ms May 26 07:58:42 volumio volumio[1774]: info: ------------------------------ 24ms May 26 07:58:42 volumio sudo[5267]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 26 07:58:42 volumio sudo[5272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 26 07:58:42 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 26 07:58:42 volumio qobuz-connect[2777]: 20260526 07:58:42.182 [2777.2777] INFO SampleApp: Stopping Local configuration server May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 26 07:58:42 volumio volumio[1774]: info: VolumeController:: Volume=46 Mute =false May 26 07:58:42 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.193+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:42 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:42.193+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id="https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" title="file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" May 26 07:58:42 volumio volumio[1774]: info: Asound.conf file unchanged, so no further update is needed May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting MPD May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting Shairport Sync May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio sudo[5283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 26 07:58:42 volumio sudo[5283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5283]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 26 07:58:42 volumio volumio[1774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 26 07:58:42 volumio volumio[1774]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 26 07:58:42 volumio qobuz-connect[2777]: 20260526 07:58:42.224 [2777.2777] INFO SampleApp: shat down connection on UNIX socket May 26 07:58:42 volumio sudo[5295]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 26 07:58:42 volumio sudo[5306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 26 07:58:42 volumio sudo[5306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') May 26 07:58:42 volumio volumio[1774]: info: MPD Permissions set May 26 07:58:42 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 26 07:58:42 volumio sudo[5272]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio systemd[1]: mpd.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 26 07:58:42 volumio systemd[1]: mpd.service: Consumed 6.651s CPU time. May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: Executing endpoint qc_getconfig May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 26 07:58:42 volumio systemd[1]: mpd.socket: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 26 07:58:42 volumio sudo[5306]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 26 07:58:42 volumio sudo[5316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 26 07:58:42 volumio sudo[5316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: Starting Shairport Sync May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.295 [5300.5300] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.296 [5300.5300] INFO VolumeManager: [0x15279c8]: Setting new playback volume: 75 May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.296 [5300.5300] INFO VolumeManager: [0x15279c8]: Setting new mute state: 0 May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.296 [5300.5300] INFO AudioStreamManager: [0x1527720]: Setting new audio download buffer size: 1048576 May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.296 [5300.5300] INFO QobuzConnect: [0x1528290]: Client initialized! May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.296 [5300.5300] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp May 26 07:58:42 volumio sudo[5295]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5297]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.306 [5300.5300] INFO LocalConfigManager: [0x1527448]: Starting Local Configuration server May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.306 [5300.5300] INFO SampleApp: Starting Local configuration server May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.306 [5300.5300] INFO SampleApp: Connected to UNIX socket client 0x1512818 May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: QOBUZ Connect daemon connected May 26 07:58:42 volumio volumio[1774]: info: Preparing to generate the ALSA configuration file May 26 07:58:42 volumio sudo[5321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 26 07:58:42 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 26 07:58:42 volumio sudo[5321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio qobuz-connect[5300]: 20260526 07:58:42.314 [5300.5300] INFO SampleApp: Stopping Local configuration server May 26 07:58:42 volumio volumio[1774]: info: Asound.conf file unchanged, so no further update is needed May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting MPD May 26 07:58:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 26 07:58:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio systemd[1]: shairport-sync.service: Consumed 2.774s CPU time. May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting Shairport Sync May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio sudo[5328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 26 07:58:42 volumio sudo[5328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5328]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio sudo[5317]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 26 07:58:42 volumio sudo[5317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 26 07:58:42 volumio sudo[5331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 26 07:58:42 volumio sudo[5331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 26 07:58:42 volumio sudo[5317]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5321]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio sudo[5343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio systemd[1]: mpd.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 26 07:58:42 volumio systemd[1]: mpd.socket: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 26 07:58:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 26 07:58:42 volumio sudo[5345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 26 07:58:42 volumio sudo[5369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: MPD Permissions set May 26 07:58:42 volumio volumio[1774]: info: Shairport-Sync Started May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5345]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5343]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5365]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 26 07:58:42 volumio sudo[5365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 26 07:58:42 volumio sudo[5369]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5365]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 26 07:58:42 volumio sudo[5379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: Starting Shairport Sync May 26 07:58:42 volumio sudo[5383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 26 07:58:42 volumio volumio[1774]: info: Preparing to generate the ALSA configuration file May 26 07:58:42 volumio sudo[5383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: Asound.conf file unchanged, so no further update is needed May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting MPD May 26 07:58:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 26 07:58:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio sudo[5386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 26 07:58:42 volumio sudo[5386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: Output device has changed, restarting Shairport Sync May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio sudo[5383]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio sudo[5386]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 26 07:58:42 volumio volumio[1774]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 26 07:58:42 volumio sudo[5388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:42 volumio systemd[1]: mpd.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 26 07:58:42 volumio systemd[1]: mpd.socket: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 26 07:58:42 volumio sudo[5413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 26 07:58:42 volumio sudo[5417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: MPD Permissions set May 26 07:58:42 volumio volumio[1774]: info: Shairport-Sync Started May 26 07:58:42 volumio sudo[5423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio sudo[5423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 07:58:42 volumio volumio[1774]: info: Starting Shairport Sync May 26 07:58:42 volumio sudo[5433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 26 07:58:42 volumio sudo[5433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 26 07:58:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 26 07:58:42 volumio sudo[5423]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 26 07:58:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 26 07:58:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio sudo[5435]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 26 07:58:42 volumio sudo[5436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 26 07:58:42 volumio sudo[5435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 26 07:58:42 volumio sudo[5436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:42 volumio sudo[5435]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5417]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5413]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 26 07:58:42 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat May 26 07:58:42 volumio sudo[5433]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio volumio[1774]: info: Shairport-Sync Started May 26 07:58:42 volumio mpd[5439]: 2026-05-26T07:58:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 26 07:58:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 26 07:58:42 volumio sudo[5388]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5331]: pam_unix(sudo:session): session closed for user root May 26 07:58:42 volumio sudo[5285]: pam_unix(sudo:session): session closed for user root May 26 07:58:43 volumio volumio[1774]: error: MPD error: The expression evaluated to a falsy value: May 26 07:58:43 volumio volumio[1774]: assert.ok(self.idling) May 26 07:58:43 volumio volumio[1774]: error: The expression evaluated to a falsy value: May 26 07:58:43 volumio volumio[1774]: assert.ok(self.idling) May 26 07:58:43 volumio volumio[1774]: error: MPD error: The expression evaluated to a falsy value: May 26 07:58:43 volumio volumio[1774]: assert.ok(self.idling) May 26 07:58:43 volumio volumio[1774]: error: The expression evaluated to a falsy value: May 26 07:58:43 volumio volumio[1774]: assert.ok(self.idling) May 26 07:58:43 volumio volumio[1774]: error: updateQueue error: null May 26 07:58:44 volumio qobuz-connect[5300]: 20260526 07:58:44.317 [5300.5300] INFO SampleApp: shat down connection on UNIX socket May 26 07:58:44 volumio volumio[1774]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 26 07:58:44 volumio volumio[1774]: info: QobuzConnect: setDeactiveState invoked May 26 07:58:44 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:44 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. May 26 07:58:44 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 26 07:58:44 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 26 07:58:44 volumio sudo[5316]: pam_unix(sudo:session): session closed for user root May 26 07:58:44 volumio sudo[5379]: pam_unix(sudo:session): session closed for user root May 26 07:58:44 volumio sudo[5436]: pam_unix(sudo:session): session closed for user root May 26 07:58:44 volumio volumio[1774]: info: Executing endpoint qc_getconfig May 26 07:58:44 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.367 [5459.5459] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.369 [5459.5459] INFO VolumeManager: [0x23499c8]: Setting new playback volume: 75 May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.369 [5459.5459] INFO VolumeManager: [0x23499c8]: Setting new mute state: 0 May 26 07:58:44 volumio volumio[1774]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 26 07:58:44 volumio volumio[1774]: info: QobuzConnect: QOBUZ Connect daemon connected May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.369 [5459.5459] INFO AudioStreamManager: [0x2349720]: Setting new audio download buffer size: 1048576 May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.369 [5459.5459] INFO QobuzConnect: [0x234a290]: Client initialized! May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.370 [5459.5459] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.375 [5459.5459] INFO LocalConfigManager: [0x2349448]: Starting Local Configuration server May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.375 [5459.5459] INFO SampleApp: Starting Local configuration server May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.375 [5459.5459] INFO SampleApp: Connected to UNIX socket client 0x2334818 May 26 07:58:44 volumio qobuz-connect[5459]: 20260526 07:58:44.517 [5459.5459] INFO SampleApp: Playback volume changed: 75 May 26 07:58:44 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:45 volumio volumio[1774]: info: TidalConnect service stoped! May 26 07:58:45 volumio volumio[1774]: info: TidalConnect service stoped! May 26 07:58:45 volumio volumio[1774]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 26 07:58:45 volumio volumio[1774]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 26 07:58:45 volumio sudo[5475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 26 07:58:45 volumio sudo[5475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 07:58:45 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. May 26 07:58:45 volumio sudo[5475]: pam_unix(sudo:session): session closed for user root May 26 07:58:45 volumio volumio[1774]: info: Executing endpoint tc_getconfig May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 26 07:58:45 volumio vtcs[5478]: STARTING TidalConnect services, version: 1.6.1 May 26 07:58:45 volumio volumio[1774]: info: TidalConnect service stoped! May 26 07:58:45 volumio volumio[1774]: info: TidalConnect service stoped! May 26 07:58:45 volumio vtcs[5478]: STARTED TidalConnect services. May 26 07:58:45 volumio volumio[1774]: info: Executing endpoint tc_connect May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 26 07:58:45 volumio volumio[1774]: info: Connecting to TidalConnect May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:58:45 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:45 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:45 volumio volumio[1774]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::servicePushState May 26 07:58:45 volumio volumio[1774]: info: CoreStateMachine::pushState May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::volumioPushState May 26 07:58:45 volumio volumio[1774]: info: CoreCommandRouter::volumioGetState May 26 07:58:45 volumio volumio[1774]: info: CorePlayQueue::getTrack 2 May 26 07:58:45 volumio volumio[1774]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 26 07:58:45 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:45.318+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:45 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:45.318+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" state=STATUS_PLAYING positionMs=18073 volume=46 May 26 07:58:45 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:45.318+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id="https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" title="file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" May 26 07:58:45 volumio volumio5-onboarding[1548]: time=2026-05-26T07:58:45.318+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.131:55649,00:00:00:00:00:00%05 @ 0x14005a0" id="https://streaming-qobuz-std.akamaized.net/file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" title="file?uid=11870533&eid=203578464&fmt=7&profile=raw&app_id=539451548&cid=4179698&etsp=1779760415&hmac=BH5Wek1fzgfJIMacqlyzjMhX1D8" May 26 07:58:45 volumio volumio[1774]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 26 07:58:45 volumio volumio[1774]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 26 07:58:45 volumio volumio[1774]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 07:58:45 volumio volumio[1774]: Error: ENOENT: no such file or directory, unlink '/tmp/Ps5ff6q0VVlSjXek5jDXRtbSufgbISoJjzI1zaDATY8WGxS03MVO4HpI9DwjJQYBPkYHqQBDzyNA2Y1PXRt0GPEyH9FAOXTLHV4C' May 26 07:58:45 volumio volumio[1774]: at Object.unlinkSync (node:fs:1899:3) May 26 07:58:45 volumio volumio[1774]: at ControllerTidalconnect.deleteCertificate (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:11265) May 26 07:58:45 volumio volumio[1774]: at TidalConnectClient. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:2774) May 26 07:58:45 volumio volumio[1774]: at TidalConnectClient.emit (node:events:514:28) May 26 07:58:45 volumio volumio[1774]: at TidalConnectClient.parseData (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:44713) May 26 07:58:45 volumio volumio[1774]: at /myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41683 May 26 07:58:45 volumio volumio[1774]: at Array.forEach () May 26 07:58:45 volumio volumio[1774]: at Socket. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41561) May 26 07:58:45 volumio volumio[1774]: at Socket.emit (node:events:514:28) May 26 07:58:45 volumio volumio[1774]: at addChunk (node:internal/streams/readable:343:12) May 26 07:58:45 volumio volumio[1774]: at readableAddChunk (node:internal/streams/readable:316:9) May 26 07:58:45 volumio volumio[1774]: at Readable.push (node:internal/streams/readable:253:10) May 26 07:58:45 volumio volumio[1774]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) { May 26 07:58:45 volumio volumio[1774]: errno: -2, May 26 07:58:45 volumio volumio[1774]: syscall: 'unlink', May 26 07:58:45 volumio volumio[1774]: code: 'ENOENT', May 26 07:58:45 volumio volumio[1774]: path: '/tmp/Ps5ff6q0VVlSjXek5jDXRtbSufgbISoJjzI1zaDATY8WGxS03MVO4HpI9DwjJQYBPkYHqQBDzyNA2Y1PXRt0GPEyH9FAOXTLHV4C' May 26 07:58:45 volumio volumio[1774]: } May 26 07:58:45 volumio volumio[1774]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 07:58:45 volumio sudo[5516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-26 07:57' May 26 07:58:45 volumio sudo[5516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"