-- Logs begin at Wed 2026-02-11 16:43:36 CST, end at Thu 2026-02-12 21:13:54 CST. -- Feb 12 21:12:03 rivo volumio[3272]: info: Collecting websocket_client (from camilladsp==1.0.0) Feb 12 21:12:03 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:03.285-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:03 rivo volumio[3272]: info: CorePlayQueue::getTrack 19 Feb 12 21:12:03 rivo volumio[3272]: info: CorePlayQueue::getTrack 20 Feb 12 21:12:03 rivo volumio[3272]: info: Prefetching next song Feb 12 21:12:03 rivo volumio[3272]: info: [1770952323338] ControllerQobuz::prefetch Feb 12 21:12:03 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/4855253" Feb 12 21:12:03 rivo volumio[3272]: STREAMING PROXY: Handling url /?data=qobuz://song/4855253 Feb 12 21:12:03 rivo volumio[3272]: info: Executing endpoint getStreamUrlqobuz Feb 12 21:12:03 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 12 21:12:03 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/d3/a3/63e9329c8cc9be6153e919e17d0ef5b60d537fed78564872951b95bcc17c/websocket_client-1.6.1-py3-none-any.whl (56kB) Feb 12 21:12:03 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:03.677-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:03 rivo volumio[3272]: info: Building wheels for collected packages: camilladsp, PyYAML Feb 12 21:12:03 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:03.866-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:03 rivo volumio[3272]: info: Running setup.py bdist_wheel for camilladsp: started Feb 12 21:12:03 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:03.897-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:05 rivo volumio[3272]: info: Running setup.py bdist_wheel for camilladsp: finished with status 'done' Feb 12 21:12:05 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:05.540-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:05 rivo volumio[3272]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-2jv4mz74/wheels/ca/47/7d/ee36beb671f74869a8e2ecb2c3fd4a28c1b7488a9c78e442b6 Feb 12 21:12:05 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:05.570-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:05 rivo volumio[3272]: info: Running setup.py bdist_wheel for PyYAML: started Feb 12 21:12:05 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:05.603-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:07 rivo volumio[3272]: info: CoreStateMachine::startPlaybackTimer Feb 12 21:12:07 rivo volumio[3272]: info: CorePlayQueue::getTrack 20 Feb 12 21:12:08 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:08 rivo volumio[3272]: info: CorePlayQueue::getTrack 20 Feb 12 21:12:08 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:08 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:08 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:08 rivo volumio[3272]: info: CorePlayQueue::getTrack 20 Feb 12 21:12:08 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:08 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:08 rivo volumio[3272]: info: [LastFM] Current track has sufficient metadata: title (Vision of Love (Live at MTV Unplugged, Kaufman Astoria Studios, New York - March 1992)) and artist (Mariah Carey) passed on explicitly Feb 12 21:12:08 rivo volumio[3272]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Feb 12 21:12:08 rivo volumio[3272]: info: getStreamUrl took 5499 milliseconds Feb 12 21:12:08 rivo volumio[3272]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=4002904&eid=4855253&fmt=6&profile=raw&app_id=539451548&cid=3853238&etsp=1770955928&hmac=39Tj3oQXoHqFEENL08q6GbMhs2Q Feb 12 21:12:08 rivo volumio[3272]: STREAMING PROXY: Requesting upstream with range: none Feb 12 21:12:08 rivo volumio[3272]: info: Running setup.py bdist_wheel for PyYAML: finished with status 'done' Feb 12 21:12:09 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:09.008-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:09 rivo volumio[3272]: info: Stored in directory: /root/.cache/pip/wheels/e6/c6/ef/4e8ee93f1b79fc90562f1600d47189799f8213023d9dadafa2 Feb 12 21:12:09 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:09.035-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:09 rivo volumio[3272]: info: Successfully built camilladsp PyYAML Feb 12 21:12:09 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:09.197-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:09 rivo volumio[3272]: info: Installing collected packages: PyYAML, websocket-client, camilladsp Feb 12 21:12:09 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:09.509-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:10 rivo volumio[3272]: info: Successfully installed PyYAML-6.0.1 camilladsp-1.0.0 websocket-client-1.6.1 Feb 12 21:12:10 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:10.108-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:10 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:10 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:10 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:10 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:10 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:10 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:14 rivo volumio[3272]: STREAMING PROXY: Upstream status code: 200 Feb 12 21:12:14 rivo volumio[3272]: STREAMING PROXY: Client closed connection Feb 12 21:12:14 rivo volumio[3272]: STREAMING PROXY: Upstream closed. Received 16384 bytes Feb 12 21:12:14 rivo volumio[3272]: STREAMING PROXY: Incomplete transfer. Expected 23437325, got 16384 Feb 12 21:12:14 rivo volumio[3272]: STREAMING PROXY: Retrying with range: bytes=16384- (attempt 1) Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:14 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/4855253" Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:14 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:14 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:14 rivo volumio[3272]: info: Feb 12 21:12:14 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:14 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:14 rivo volumio[3272]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/4855253" took 12 milliseconds Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 17ms Feb 12 21:12:14 rivo volumio[3272]: info: sendMpdCommand status took 12 milliseconds Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 11ms Feb 12 21:12:14 rivo volumio[3272]: info: sendMpdCommand status took 9 milliseconds Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 9ms Feb 12 21:12:14 rivo volumio[3272]: info: sendMpdCommand status took 7 milliseconds Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand consume 1 Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 20 Feb 12 21:12:14 rivo volumio[3272]: 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} Feb 12 21:12:14 rivo volumio[3272]: verbose: CURRENT POSITION 20 Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::syncState stateService stop Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::play index undefined Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 12 21:12:14 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::startPlaybackTimer Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: [1770952334934] ControllerQobuz::clearAddPlayTrack Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 112ms Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 107ms Feb 12 21:12:14 rivo volumio[3272]: info: ------------------------------ 105ms Feb 12 21:12:14 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand stop Feb 12 21:12:14 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:14 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:14 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:14 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:15 rivo volumio[3272]: info: Feb 12 21:12:15 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:15 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:15 rivo volumio[3272]: info: Feb 12 21:12:15 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:15 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:15 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:15 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:15 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:15 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:15 rivo volumio[3272]: info: ------------------------------ 201ms Feb 12 21:12:15 rivo volumio[3272]: info: sendMpdCommand consume 1 took 194 milliseconds Feb 12 21:12:15 rivo volumio[3272]: info: sendMpdCommand stop took 99 milliseconds Feb 12 21:12:15 rivo volumio[3272]: info: ------------------------------ 25ms Feb 12 21:12:15 rivo volumio[3272]: info: ------------------------------ 26ms Feb 12 21:12:15 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand clear Feb 12 21:12:15 rivo volumio[3272]: info: [LastFM] Current track has sufficient metadata: title (Old Devil Moon ) and artist (Tony Bennett) passed on explicitly Feb 12 21:12:15 rivo volumio[3272]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Feb 12 21:12:15 rivo volumio[3272]: info: Feb 12 21:12:15 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:15 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:15 rivo volumio[3272]: info: sendMpdCommand clear took 60 milliseconds Feb 12 21:12:15 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/52866" Feb 12 21:12:15 rivo volumio[3272]: info: Feb 12 21:12:15 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:15 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:15 rivo volumio[3272]: info: Feb 12 21:12:15 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:15 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:15 rivo volumio[3272]: STREAMING PROXY: Handling url /?data=qobuz://song/52866 Feb 12 21:12:15 rivo volumio[3272]: error: updateQueue error: null Feb 12 21:12:15 rivo volumio[3272]: info: ------------------------------ 10ms Feb 12 21:12:15 rivo volumio[3272]: info: Executing endpoint getStreamUrlqobuz Feb 12 21:12:15 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 12 21:12:15 rivo volumio[3272]: STREAMING PROXY: Resuming with range: bytes=16384- Feb 12 21:12:16 rivo volumio[3272]: info: Collecting git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 Feb 12 21:12:16 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:16.836-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:16 rivo volumio[3272]: info: Cloning https://github.com/HEnquist/pycamilladsp-plot.git (to revision v1.0.2) to /tmp/pip-req-build-qlqbebph Feb 12 21:12:16 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:16.860-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:16 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:16 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:17 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:17 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:17 rivo volumio[3272]: info: Executing endpoint metavolumio Feb 12 21:12:17 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 12 21:12:17 rivo volumio[3272]: info: MRS: STARTING volumioStreaming Feb 12 21:12:17 rivo sudo[28114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/stream.m3u8 /tmp/hls/stream145.ts /tmp/hls/stream146.ts /tmp/hls/stream147.ts /tmp/hls/stream148.ts /tmp/hls/stream149.ts Feb 12 21:12:17 rivo sudo[28114]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:17 rivo sudo[28114]: pam_unix(sudo:session): session closed for user root Feb 12 21:12:17 rivo sudo[28117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Feb 12 21:12:17 rivo sudo[28117]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:17 rivo systemd[1]: Stopping VolumioStreamingService... Feb 12 21:12:17 rivo systemd[1]: volumioStreaming.service: Main process exited, code=killed, status=15/TERM Feb 12 21:12:17 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:12:18 rivo systemd[1]: volumioStreaming.service: Succeeded. Feb 12 21:12:18 rivo systemd[1]: Stopped VolumioStreamingService. Feb 12 21:12:18 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:12:18 rivo systemd[1]: Started VolumioStreamingService. Feb 12 21:12:18 rivo sudo[28117]: pam_unix(sudo:session): session closed for user root Feb 12 21:12:18 rivo volumio[3272]: info: MRS: volumioStreaming STARTED Feb 12 21:12:18 rivo sudo[28122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 12 21:12:18 rivo sudo[28122]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:18 rivo sudo[28122]: pam_unix(sudo:session): session closed for user root Feb 12 21:12:20 rivo volumio[3272]: info: getStreamUrl took 5405 milliseconds Feb 12 21:12:20 rivo volumio[3272]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=4002904&eid=52866&fmt=6&profile=raw&app_id=539451548&cid=3853238&etsp=1770955940&hmac=7ART7uaJ4J8XDaMzF2KM8n47Db0 Feb 12 21:12:20 rivo volumio[3272]: STREAMING PROXY: Requesting upstream with range: none Feb 12 21:12:20 rivo volumio[3272]: STREAMING PROXY: Resume upstream status code: 206 Feb 12 21:12:22 rivo volumio[3272]: STREAMING PROXY: Resume ended. Received 23420941 bytes Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Upstream status code: 200 Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Client closed connection Feb 12 21:12:26 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/52866" Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Upstream closed. Received 15644 bytes Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Incomplete transfer. Expected 21872875, got 15644 Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Retrying with range: bytes=15644- (attempt 1) Feb 12 21:12:26 rivo volumio[3272]: error: updateQueue error: null Feb 12 21:12:26 rivo volumio[3272]: info: ------------------------------ 11389ms Feb 12 21:12:26 rivo volumio[3272]: info: ------------------------------ 11387ms Feb 12 21:12:26 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:26 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:26 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:26 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:26 rivo volumio[3272]: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:12:26 rivo volumio[3272]: info: Feb 12 21:12:26 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:26 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:26 rivo volumio[3272]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/52866" took 8 milliseconds Feb 12 21:12:26 rivo volumio[3272]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 12 21:12:26 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand play Feb 12 21:12:26 rivo volumio[3272]: STREAMING PROXY: Handling url /?data=qobuz://song/52866 Feb 12 21:12:26 rivo volumio[3272]: info: Feb 12 21:12:26 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:26 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:26 rivo volumio[3272]: info: Feb 12 21:12:26 rivo volumio[3272]: ---------------------------- MPD announces system playlist update Feb 12 21:12:26 rivo volumio[3272]: info: Ignoring MPD Status Update Feb 12 21:12:26 rivo volumio[3272]: info: ------------------------------ 12ms Feb 12 21:12:26 rivo volumio[3272]: info: sendMpdCommand play took 11 milliseconds Feb 12 21:12:26 rivo volumio[3272]: info: ------------------------------ 7ms Feb 12 21:12:26 rivo volumio[3272]: info: ------------------------------ 4ms Feb 12 21:12:26 rivo volumio[3272]: info: Executing endpoint getStreamUrlqobuz Feb 12 21:12:26 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 12 21:12:27 rivo volumio[3272]: STREAMING PROXY: Resuming with range: bytes=15644- Feb 12 21:12:29 rivo volumio[3272]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (6.0.1) Feb 12 21:12:29 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:29.568-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:29 rivo volumio[3272]: info: Collecting jsonschema (from camilladsp-plot==1.0.2) Feb 12 21:12:29 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:29.639-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:32 rivo volumio[3272]: info: getStreamUrl took 5488 milliseconds Feb 12 21:12:32 rivo volumio[3272]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=4002904&eid=52866&fmt=6&profile=raw&app_id=539451548&cid=3853238&etsp=1770955951&hmac=M4WlnVMiOZ6nAfTrrLWejyaNWT8 Feb 12 21:12:32 rivo volumio[3272]: STREAMING PROXY: Requesting upstream with range: none Feb 12 21:12:32 rivo volumio[3272]: STREAMING PROXY: Resume upstream status code: 206 Feb 12 21:12:34 rivo volumio[3272]: STREAMING PROXY: Resume ended. Received 21857231 bytes Feb 12 21:12:35 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/c1/97/c698bd9350f307daad79dd740806e1a59becd693bd11443a0f531e3229b3/jsonschema-4.17.3-py3-none-any.whl (90kB) Feb 12 21:12:35 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:35.554-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:35 rivo volumio[3272]: info: Requirement already satisfied: attrs>=17.4.0 in /usr/lib/python3/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (18.2.0) Feb 12 21:12:35 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:35.938-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:36 rivo volumio[3272]: info: Collecting pkgutil-resolve-name>=1.3.10; python_version < "3.9" (from jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:36 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:36.064-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:36 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/c9/5c/3d4882ba113fd55bdba9326c1e4c62a15e674a2501de4869e6bd6301f87e/pkgutil_resolve_name-1.3.10-py3-none-any.whl Feb 12 21:12:36 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:36.166-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:36 rivo volumio[3272]: info: Collecting importlib-resources>=1.4.0; python_version < "3.9" (from jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:36 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:36.352-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:36 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/38/71/c13ea695a4393639830bf96baea956538ba7a9d06fcce7cef10bfff20f72/importlib_resources-5.12.0-py3-none-any.whl Feb 12 21:12:36 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:36.899-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:37 rivo volumio[3272]: STREAMING PROXY: Upstream status code: 200 Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 31 milliseconds Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 40 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 30 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 15 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 11 milliseconds Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"960 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus stop Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 105ms Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: Feb 12 21:12:37 rivo volumio[3272]: ---------------------------- MPD announces state update: player Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::getState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand status Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 39 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 39 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 37 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 10 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand status took 8 milliseconds Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseState Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1006,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"960 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:37 rivo volumio[3272]: info: Received an update from plugin. extracting info from payload Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1006,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"960 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:37 rivo volumio[3272]: info: Received an update from plugin. extracting info from payload Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"945 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:37 rivo volumio[3272]: info: Received an update from plugin. extracting info from payload Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 370ms Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 368ms Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 355ms Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 276 milliseconds Feb 12 21:12:37 rivo volumio[3272]: info: sendMpdCommand playlistinfo took 276 milliseconds Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: verbose: ControllerMpd::parseTrackInfo Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"741 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:37 rivo volumio[3272]: info: Received an update from plugin. extracting info from payload Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: ControllerMpd::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::servicePushState Feb 12 21:12:37 rivo volumio[3272]: info: CorePlayQueue::getTrack 21 Feb 12 21:12:37 rivo volumio[3272]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":199,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"741 Kbps","isStreaming":false,"title":"52866","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/52866","trackType":"qobuz"} Feb 12 21:12:37 rivo volumio[3272]: verbose: CURRENT POSITION 21 Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState stateService play Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::syncState currentStatus play Feb 12 21:12:37 rivo volumio[3272]: info: Received an update from plugin. extracting info from payload Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: CoreStateMachine::pushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioPushState Feb 12 21:12:37 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output update for this device Feb 12 21:12:37 rivo volumio[3272]: info: MRS: Pushing multiroomSync output Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 503ms Feb 12 21:12:37 rivo volumio[3272]: info: ------------------------------ 501ms Feb 12 21:12:37 rivo volumio[3272]: info: [LastFM] Current track has sufficient metadata: title (The Conquering Lion (Live)) and artist (Lauryn Hill) passed on explicitly Feb 12 21:12:37 rivo volumio[3272]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Feb 12 21:12:37 rivo volumio[3272]: info: Collecting typing-extensions; python_version < "3.8" (from jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:37 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:37.959-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:38 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/ec/6b/63cc3df74987c36fe26157ee12e09e8f9db4de771e0f3404263117e75b95/typing_extensions-4.7.1-py3-none-any.whl Feb 12 21:12:38 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:38.164-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:38 rivo volumio[3272]: info: Collecting pyrsistent!=0.17.0,!=0.17.1,!=0.17.2,>=0.14.0 (from jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:38 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:38.508-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:39 rivo volumio[3272]: STREAMING PROXY: Upstream closed. Received 21872875 bytes Feb 12 21:12:39 rivo volumio[3272]: STREAMING PROXY: Client closed connection Feb 12 21:12:39 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/64/de/375aa14daaee107f987da76ca32f7a907fea00fa8b8afb67dc09bec0de91/pyrsistent-0.19.3-py3-none-any.whl (57kB) Feb 12 21:12:39 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:39.421-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:39 rivo volumio[3272]: info: Collecting importlib-metadata; python_version < "3.8" (from jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:39 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:39.716-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:40 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/ff/94/64287b38c7de4c90683630338cf28f129decbba0a44f0c6db35a873c73c4/importlib_metadata-6.7.0-py3-none-any.whl Feb 12 21:12:40 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:40.628-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:40 rivo volumio[3272]: info: Collecting zipp>=3.1.0; python_version < "3.10" (from importlib-resources>=1.4.0; python_version < "3.9"->jsonschema->camilladsp-plot==1.0.2) Feb 12 21:12:40 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:40.995-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:41 rivo volumio[3272]: info: Downloading https://files.pythonhosted.org/packages/5b/fa/c9e82bbe1af6266adf08afb563905eb87cab83fde00a0a08963510621047/zipp-3.15.0-py3-none-any.whl Feb 12 21:12:41 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:41.399-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:41 rivo volumio[3272]: info: Building wheels for collected packages: camilladsp-plot Feb 12 21:12:41 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:41.649-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:41 rivo volumio[3272]: info: Running setup.py bdist_wheel for camilladsp-plot: started Feb 12 21:12:41 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:41.676-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:43 rivo volumio[3272]: info: Running setup.py bdist_wheel for camilladsp-plot: finished with status 'done' Feb 12 21:12:43 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:43.501-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:43 rivo volumio[3272]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-h_b1pkq9/wheels/11/e1/43/8275af2f537d569c7097d202b4955f9aec629859be39dab2e9 Feb 12 21:12:43 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:43.534-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:43 rivo volumio[3272]: info: Successfully built camilladsp-plot Feb 12 21:12:43 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:43.569-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:44 rivo volumio[3272]: info: Installing collected packages: pkgutil-resolve-name, zipp, importlib-resources, typing-extensions, pyrsistent, importlib-metadata, jsonschema, camilladsp-plot Feb 12 21:12:44 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:44.568-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:45 rivo volumio[3272]: info: Successfully installed camilladsp-plot-1.0.2 importlib-metadata-6.7.0 importlib-resources-5.12.0 jsonschema-4.17.3 pkgutil-resolve-name-1.3.10 pyrsistent-0.19.3 typing-extensions-4.7.1 zipp-3.15.0 Feb 12 21:12:45 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:45.885-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:46 rivo volumio[3272]: info: copying hw detection script Feb 12 21:12:46 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:46.221-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:46 rivo volumio[3272]: info: Detected cpu architecture as aarch64 Feb 12 21:12:46 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:46.252-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:58 rivo volumio[3272]: info: camilladsp Feb 12 21:12:58 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:58.054-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:58 rivo sudo[28361]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params Feb 12 21:12:58 rivo sudo[28361]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:58 rivo sudo[28361]: pam_unix(sudo:session): session closed for user root Feb 12 21:12:58 rivo sudo[28363]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params Feb 12 21:12:58 rivo sudo[28363]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:58 rivo sudo[28363]: pam_unix(sudo:session): session closed for user root Feb 12 21:12:58 rivo sudo[28365]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc Feb 12 21:12:58 rivo sudo[28365]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:12:58 rivo volumio[3272]: info: Reading package lists... Feb 12 21:12:58 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:58.725-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:59 rivo volumio[3272]: info: Building dependency tree... Feb 12 21:12:59 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:59.520-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:12:59 rivo volumio[3272]: info: Reading state information... Feb 12 21:12:59 rivo volumio5-onboarding[4146]: time=2026-02-12T21:12:59.556-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:01 rivo volumio[3272]: info: The following NEW packages will be installed: Feb 12 21:13:01 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:01.032-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:01 rivo volumio[3272]: info: drc Feb 12 21:13:01 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:01.080-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:11 rivo volumio[3272]: info: 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. Feb 12 21:13:11 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:11.679-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:11 rivo volumio[3272]: info: Need to get 118 kB of archives. Feb 12 21:13:11 rivo volumio[3272]: info: After this operation, 471 kB of additional disk space will be used. Feb 12 21:13:11 rivo volumio[3272]: info: Get:1 http://archive.debian.org/debian buster/main armhf drc armhf 3.2.2~dfsg0-2 [118 kB] Feb 12 21:13:11 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:11.720-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:11 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:11.723-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:11 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:11.730-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:13 rivo volumio[3272]: info: Fetched 118 kB in 11s (11.2 kB/s) Feb 12 21:13:13 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:13.373-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:13 rivo volumio[3272]: info: Selecting previously unselected package drc. Feb 12 21:13:13 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:13.501-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:14 rivo volumio[3272]: [620B blob data] Feb 12 21:13:14 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:14.951-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:14 rivo volumio[3272]: info: Preparing to unpack .../drc_3.2.2~dfsg0-2_armhf.deb ... Feb 12 21:13:14 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:14.988-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:14 rivo volumio[3272]: info: Unpacking drc (3.2.2~dfsg0-2) ... Feb 12 21:13:15 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:15.018-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:15 rivo volumio[3272]: info: Setting up drc (3.2.2~dfsg0-2) ... Feb 12 21:13:15 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:15.429-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:15 rivo volumio[3272]: info: Processing triggers for man-db (2.8.5-2) ... Feb 12 21:13:15 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:15.474-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:16 rivo sudo[28365]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:16 rivo volumio[3272]: Plugin install end detected on script Feb 12 21:13:16 rivo sudo[25809]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:16 rivo volumio[3272]: info: Install script completed Feb 12 21:13:16 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:16.596-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:16 rivo volumio[3272]: info: Adding reference to registry Feb 12 21:13:16 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:16.622-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:16 rivo volumio[3272]: info: Done installing plugin. Feb 12 21:13:16 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 21:13:16 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 12 21:13:16 rivo volumio[3272]: info: Folder /tmp/plugins removed Feb 12 21:13:16 rivo volumio[3272]: info: Folder /tmp/downloaded_plugin.zip removed Feb 12 21:13:16 rivo volumio[3272]: info: Folder /data/temp removed Feb 12 21:13:20 rivo volumio[3272]: info: Enabling plugin fusiondsp Feb 12 21:13:20 rivo volumio[3272]: info: Loading plugin "fusiondsp"... Feb 12 21:13:21 rivo volumio[3272]: info: Preparing to generate the ALSA configuration file Feb 12 21:13:21 rivo volumio[3272]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 12 21:13:21 rivo volumio[3272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 12 21:13:21 rivo volumio[3272]: info: Reading ALSA contributions from plugins. Feb 12 21:13:21 rivo volumio[3272]: info: Asound.conf file written Feb 12 21:13:21 rivo sudo[28524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 12 21:13:21 rivo sudo[28524]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:21 rivo sudo[28524]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:21 rivo kernel: Fine tdm clk setting range (0~2000000), 12287994 Feb 12 21:13:21 rivo kernel: Err: can not set rate to 4278967296! Feb 12 21:13:21 rivo kernel: Range[3920000 - 500000000] Feb 12 21:13:21 rivo kernel: out of value, fixed it Feb 12 21:13:21 rivo kernel: id=0 set inskew=0 Feb 12 21:13:21 rivo volumio[3272]: No protocol specified Feb 12 21:13:21 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:21 rivo volumio[3272]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted Feb 12 21:13:21 rivo volumio[3272]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted Feb 12 21:13:21 rivo volumio[3272]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted Feb 12 21:13:21 rivo volumio[3272]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted Feb 12 21:13:21 rivo volumio[3272]: info: Output device has changed, restarting MPD Feb 12 21:13:21 rivo sudo[28529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:13:21 rivo sudo[28529]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:21 rivo sudo[28529]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:21 rivo volumio[3272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 12 21:13:21 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:21 rivo sudo[28532]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:13:21 rivo sudo[28532]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:22 rivo volumio[3272]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: PLUGIN START: fusiondsp Feb 12 21:13:22 rivo volumio[3272]: info: Loading i18n strings for locale en Feb 12 21:13:22 rivo systemd[1]: Stopping Music Player Daemon... Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: FusionDsp - mixtype--------------------- None Feb 12 21:13:22 rivo volumio[3272]: info: Preparing to generate the ALSA configuration file Feb 12 21:13:22 rivo volumio[3272]: info: Done. Feb 12 21:13:22 rivo volumio[3272]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 12 21:13:22 rivo volumio[3272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 12 21:13:22 rivo volumio[3272]: info: Reading ALSA contributions from plugins. Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo volumio[3272]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 12 21:13:22 rivo volumio[3272]: info: MPD Permissions set Feb 12 21:13:22 rivo sudo[28540]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 12 21:13:22 rivo sudo[28540]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo systemd[1]: mpd.service: Succeeded. Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo systemd[1]: Stopped Music Player Daemon. Feb 12 21:13:22 rivo systemd[1]: Starting Music Player Daemon... Feb 12 21:13:22 rivo sudo[28540]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 12 21:13:22 rivo sudo[28553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 12 21:13:22 rivo sudo[28553]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo qobuz-connect[3807]: 20260212 21:13:22.354 [3807.3807] INFO SampleApp: Stopping Local configuration server Feb 12 21:13:22 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Feb 12 21:13:22 rivo qobuz-connect[3807]: 20260212 21:13:22.364 [3807.3807] INFO SampleApp: shat down connection on UNIX socket Feb 12 21:13:22 rivo systemd[1]: qobuz-connect.service: Succeeded. Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Feb 12 21:13:22 rivo systemd[1]: Started Volumio Qobuz Connect Service. Feb 12 21:13:22 rivo sudo[28553]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:22 rivo sudo[28542]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo sudo[28542]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:22 rivo sudo[28542]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Feb 12 21:13:22 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:22 rivo volumio[3272]: info: Asound.conf file unchanged, so no further update is needed Feb 12 21:13:22 rivo volumio[3272]: info: Output device has changed, restarting MPD Feb 12 21:13:22 rivo sudo[28568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:13:22 rivo volumio[3272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo sudo[28568]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo sudo[28568]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo sudo[28570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:13:22 rivo sudo[28570]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 12 21:13:22 rivo systemd[1]: mpd.service: Succeeded. Feb 12 21:13:22 rivo systemd[1]: Stopped Music Player Daemon. Feb 12 21:13:22 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:22 rivo volumio[3272]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo systemd[1]: Starting Music Player Daemon... Feb 12 21:13:22 rivo sudo[28582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 12 21:13:22 rivo sudo[28582]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo sudo[28582]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:13:22 rivo volumio[3272]: info: Not Reporting Auto name since its the default one Feb 12 21:13:22 rivo sudo[28576]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:13:22 rivo sudo[28576]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo sudo[28588]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 12 21:13:22 rivo sudo[28588]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo sudo[28576]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Feb 12 21:13:22 rivo systemd[1]: qobuz-connect.service: Main process exited, code=killed, status=2/INT Feb 12 21:13:22 rivo systemd[1]: qobuz-connect.service: Succeeded. Feb 12 21:13:22 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Feb 12 21:13:22 rivo volumio[3272]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 12 21:13:22 rivo volumio[3272]: info: MPD Permissions set Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:22 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:22 rivo volumio[3272]: info: Executing endpoint qc_getconfig Feb 12 21:13:22 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 12 21:13:22 rivo systemd[1]: Started Volumio Qobuz Connect Service. Feb 12 21:13:22 rivo sudo[28588]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Feb 12 21:13:23 rivo volumio[3272]: No protocol specified Feb 12 21:13:23 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:23 rivo volumio[3272]: info: Configured Audio card not found, not starting RAAT Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:13:23 rivo volumio[3272]: info: Not Reporting Auto name since its the default one Feb 12 21:13:23 rivo volumio[3272]: info: Executing endpoint qc_getconfig Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.374 [28592.28592] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.380 [28592.28592] INFO VolumeManager: [0xacc13660]: Setting new playback volume: 75 Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.380 [28592.28592] INFO VolumeManager: [0xacc13660]: Setting new mute state: 0 Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.380 [28592.28592] INFO QobuzConnect: [0xacc14030]: Client initialized! Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.380 [28592.28592] INFO SampleApp: Starting Avahi advertising, name: RIVO, service name: _qobuz-connect._tcp Feb 12 21:13:23 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 12 21:13:23 rivo volumio[3272]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.400 [28592.28592] INFO LocalConfigManager: [0xacc12f40]: Starting Local Configuration server Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.401 [28592.28592] INFO SampleApp: Starting Local configuration server Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.402 [28592.28592] INFO SampleApp: Connected to UNIX socket client 0xacc08ed8 Feb 12 21:13:23 rivo volumio[3272]: No protocol specified Feb 12 21:13:23 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:23 rivo volumio[3272]: info: Configured Audio card not found, not starting RAAT Feb 12 21:13:23 rivo qobuz-connect[28592]: 20260212 21:13:23.523 [28592.28592] INFO SampleApp: Playback volume changed: 75 Feb 12 21:13:23 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:24 rivo volumio[3272]: info: camilladsp spawned new process with pid 28620, instance 1, run: true Feb 12 21:13:24 rivo volumio[3272]: info: camilladsp service started and running in background, instance 1 Feb 12 21:13:24 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:24 rivo volumio[3272]: No protocol specified Feb 12 21:13:24 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:24 rivo volumio[3272]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 12 21:13:24 rivo volumio[3272]: cannot open device 'volumioHw': No such device Feb 12 21:13:24 rivo volumio[3272]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Feb 12 21:13:24 rivo volumio[3272]: No protocol specified Feb 12 21:13:24 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:24 rivo volumio[3272]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 12 21:13:24 rivo volumio[3272]: cannot open device 'volumioHw': No such device Feb 12 21:13:24 rivo volumio[3272]: info: FusionDsp loaded Feb 12 21:13:24 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 21:13:24 rivo sudo[28627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 12 21:13:24 rivo sudo[28627]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:24 rivo volumio[3272]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 12 21:13:24 rivo volumio[3272]: info: Adding Signal Path Element [object Object] Feb 12 21:13:24 rivo volumio[3272]: info: Adding fusiondspeq DSP Signal Path Element Feb 12 21:13:24 rivo volumio[3272]: info: Additional DSP elements updated Feb 12 21:13:24 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:24 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:24 rivo volumio[3272]: info: Updating RAAT Signal Path Feb 12 21:13:24 rivo volumio[3272]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Feb 12 21:13:24 rivo volumio[3272]: info: FusionDsp - ---- installed callbackRead Feb 12 21:13:24 rivo volumio[3272]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 12 21:13:24 rivo systemd[1]: Started FusionDsp Daemon. Feb 12 21:13:24 rivo sudo[28627]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:24 rivo volumio[3272]: error: FusionDsp - WebSocket error: [object Object] Feb 12 21:13:24 rivo volumio[3272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Feb 12 21:13:25 rivo mpd[28591]: Feb 12 21:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 21:13:25 rivo volumio[3272]: 0+0 records in Feb 12 21:13:25 rivo volumio[3272]: 0+0 records out Feb 12 21:13:25 rivo volumio[3272]: 0 bytes copied, 0.000226543 s, 0.0 kB/s Feb 12 21:13:25 rivo systemd[1]: Started Music Player Daemon. Feb 12 21:13:25 rivo sudo[28532]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:25 rivo sudo[28570]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28636, instance 1, run: true Feb 12 21:13:25 rivo volumio[3272]: error: MPD error: The expression evaluated to a falsy value: Feb 12 21:13:25 rivo volumio[3272]: assert.ok(self.idling) Feb 12 21:13:25 rivo volumio[3272]: error: The expression evaluated to a falsy value: Feb 12 21:13:25 rivo volumio[3272]: assert.ok(self.idling) Feb 12 21:13:25 rivo volumio[3272]: error: updateQueue error: null Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28643, instance 1, run: true Feb 12 21:13:25 rivo qobuz-connect[28592]: 20260212 21:13:25.683 [28592.28650] INFO SampleApp: API endpoint invoked: get-display-info Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28651, instance 1, run: true Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28658, instance 1, run: true Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28665, instance 1, run: true Feb 12 21:13:25 rivo volumio[3272]: info: camilladsp spawned new process with pid 28672, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28679, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28686, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28693, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: RAAT: Requesting Headphone Status Feb 12 21:13:26 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28700, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28707, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: RAAT: Requesting Headphone Status Feb 12 21:13:26 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Feb 12 21:13:26 rivo qobuz-connect[28592]: 20260212 21:13:26.482 [28592.28650] INFO SampleApp: API endpoint invoked: get-display-info Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28714, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28723, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28730, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28737, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28744, instance 1, run: true Feb 12 21:13:26 rivo volumio[3272]: info: camilladsp spawned new process with pid 28751, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: info: camilladsp spawned new process with pid 28758, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: info: camilladsp spawned new process with pid 28765, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: info: camilladsp spawned new process with pid 28772, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: info: Enabling plugin fusiondsp Feb 12 21:13:27 rivo volumio[3272]: info: Loading plugin "fusiondsp"... Feb 12 21:13:27 rivo volumio[3272]: info: Applying required configuration parameters for plugin fusiondsp Feb 12 21:13:27 rivo volumio[3272]: info: Preparing to generate the ALSA configuration file Feb 12 21:13:27 rivo volumio[3272]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 12 21:13:27 rivo volumio[3272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 12 21:13:27 rivo volumio[3272]: info: Reading ALSA contributions from plugins. Feb 12 21:13:27 rivo volumio[3272]: info: Asound.conf file unchanged, so no further update is needed Feb 12 21:13:27 rivo volumio[3272]: info: Output device has changed, restarting MPD Feb 12 21:13:27 rivo sudo[28781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:13:27 rivo sudo[28781]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:27 rivo volumio[3272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:27 rivo sudo[28781]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:27 rivo sudo[28784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:13:27 rivo sudo[28784]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:27 rivo systemd[1]: Stopping Music Player Daemon... Feb 12 21:13:27 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:27 rivo volumio[3272]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:27 rivo volumio[3272]: info: PLUGIN START: fusiondsp Feb 12 21:13:27 rivo volumio[3272]: info: Loading i18n strings for locale en Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:27 rivo volumio[3272]: info: FusionDsp - mixtype--------------------- None Feb 12 21:13:27 rivo volumio[3272]: info: Preparing to generate the ALSA configuration file Feb 12 21:13:27 rivo volumio[3272]: info: Done. Feb 12 21:13:27 rivo systemd[1]: mpd.service: Succeeded. Feb 12 21:13:27 rivo systemd[1]: Stopped Music Player Daemon. Feb 12 21:13:27 rivo systemd[1]: Starting Music Player Daemon... Feb 12 21:13:27 rivo volumio[3272]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Feb 12 21:13:27 rivo volumio[3272]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 12 21:13:27 rivo volumio[3272]: info: Reading ALSA contributions from plugins. Feb 12 21:13:27 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:27 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:27 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:27 rivo volumio[3272]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 12 21:13:27 rivo volumio[3272]: info: MPD Permissions set Feb 12 21:13:27 rivo sudo[28794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 12 21:13:27 rivo sudo[28794]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:27 rivo volumio[3272]: info: camilladsp spawned new process with pid 28796, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: error: Upnp client error: Error: This socket has been ended by the other party Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:27 rivo sudo[28794]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:27 rivo sudo[28790]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:13:27 rivo sudo[28790]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:27 rivo sudo[28803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 12 21:13:27 rivo sudo[28803]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:27 rivo sudo[28790]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 12 21:13:27 rivo qobuz-connect[28592]: 20260212 21:13:27.744 [28592.28592] INFO SampleApp: Stopping Local configuration server Feb 12 21:13:27 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Feb 12 21:13:27 rivo qobuz-connect[28592]: 20260212 21:13:27.755 [28592.28592] INFO SampleApp: shat down connection on UNIX socket Feb 12 21:13:27 rivo systemd[1]: qobuz-connect.service: Succeeded. Feb 12 21:13:27 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:27 rivo systemd[1]: Started Volumio Qobuz Connect Service. Feb 12 21:13:27 rivo sudo[28803]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:27 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:27 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:27 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Feb 12 21:13:27 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:27 rivo volumio[3272]: info: camilladsp spawned new process with pid 28814, instance 1, run: true Feb 12 21:13:27 rivo volumio[3272]: info: Executing endpoint qc_getconfig Feb 12 21:13:27 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.924 [28813.28813] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.930 [28813.28813] INFO VolumeManager: [0xab65d660]: Setting new playback volume: 75 Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.930 [28813.28813] INFO VolumeManager: [0xab65d660]: Setting new mute state: 0 Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.930 [28813.28813] INFO QobuzConnect: [0xab65e030]: Client initialized! Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.931 [28813.28813] INFO SampleApp: Starting Avahi advertising, name: RIVO, service name: _qobuz-connect._tcp Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.960 [28813.28813] INFO LocalConfigManager: [0xab65cf40]: Starting Local Configuration server Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.960 [28813.28813] INFO SampleApp: Starting Local configuration server Feb 12 21:13:27 rivo qobuz-connect[28813]: 20260212 21:13:27.961 [28813.28813] INFO SampleApp: Connected to UNIX socket client 0xab652ed8 Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: Not Reporting Auto name since its the default one Feb 12 21:13:28 rivo volumio[3272]: info: Asound.conf file unchanged, so no further update is needed Feb 12 21:13:28 rivo volumio[3272]: info: Output device has changed, restarting MPD Feb 12 21:13:28 rivo sudo[28830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 21:13:28 rivo sudo[28830]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:28 rivo qobuz-connect[28813]: 20260212 21:13:28.074 [28813.28813] INFO SampleApp: Playback volume changed: 75 Feb 12 21:13:28 rivo sudo[28830]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:28 rivo volumio[3272]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo sudo[28833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 21:13:28 rivo sudo[28833]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:28 rivo volumio[3272]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Feb 12 21:13:28 rivo systemd[1]: mpd.service: Succeeded. Feb 12 21:13:28 rivo systemd[1]: Stopped Music Player Daemon. Feb 12 21:13:28 rivo systemd[1]: Starting Music Player Daemon... Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:28 rivo sudo[28842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 12 21:13:28 rivo sudo[28842]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:28 rivo volumio[3272]: info: camilladsp spawned new process with pid 28844, instance 1, run: true Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:28 rivo sudo[28842]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:28 rivo volumio[3272]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Feb 12 21:13:28 rivo volumio[3272]: info: MPD Permissions set Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Feb 12 21:13:28 rivo sudo[28851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 12 21:13:28 rivo sudo[28851]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:28 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Feb 12 21:13:28 rivo qobuz-connect[28813]: 20260212 21:13:28.400 [28813.28813] INFO SampleApp: Stopping Local configuration server Feb 12 21:13:28 rivo sudo[28841]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 21:13:28 rivo sudo[28841]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:28 rivo qobuz-connect[28813]: 20260212 21:13:28.415 [28813.28813] INFO SampleApp: shat down connection on UNIX socket Feb 12 21:13:28 rivo systemd[1]: qobuz-connect.service: Succeeded. Feb 12 21:13:28 rivo sudo[28841]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:28 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Feb 12 21:13:28 rivo systemd[1]: Started Volumio Qobuz Connect Service. Feb 12 21:13:28 rivo sudo[28851]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:28 rivo volumio[3272]: No protocol specified Feb 12 21:13:28 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:28 rivo volumio[3272]: info: Configured Audio card not found, not starting RAAT Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:28 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: setDeactiveState invoked Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:28 rivo volumio[3272]: info: camilladsp spawned new process with pid 28865, instance 1, run: true Feb 12 21:13:28 rivo volumio[3272]: info: Executing endpoint qc_getconfig Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.697 [28856.28856] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.721 [28856.28856] INFO VolumeManager: [0xaac71660]: Setting new playback volume: 75 Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.721 [28856.28856] INFO VolumeManager: [0xaac71660]: Setting new mute state: 0 Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.721 [28856.28856] INFO QobuzConnect: [0xaac72030]: Client initialized! Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.721 [28856.28856] INFO SampleApp: Starting Avahi advertising, name: RIVO, service name: _qobuz-connect._tcp Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.738 [28856.28856] INFO LocalConfigManager: [0xaac70f40]: Starting Local Configuration server Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.738 [28856.28856] INFO SampleApp: Starting Local configuration server Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.739 [28856.28856] INFO SampleApp: Connected to UNIX socket client 0xaac66ed8 Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 21:13:28 rivo volumio[3272]: info: Not Reporting Auto name since its the default one Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 12 21:13:28 rivo volumio[3272]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 12 21:13:28 rivo volumio[3272]: info: camilladsp spawned new process with pid 28880, instance 1, run: true Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Feb 12 21:13:28 rivo qobuz-connect[28856]: 20260212 21:13:28.847 [28856.28856] INFO SampleApp: Playback volume changed: 75 Feb 12 21:13:28 rivo volumio[3272]: No protocol specified Feb 12 21:13:28 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:28 rivo volumio[3272]: info: Configured Audio card not found, not starting RAAT Feb 12 21:13:28 rivo volumio[3272]: info: CoreCommandRouter::volumioGetState Feb 12 21:13:28 rivo volumio[3272]: info: camilladsp spawned new process with pid 28889, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28907, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28921, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28928, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28935, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28942, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Feb 12 21:13:29 rivo volumio[3272]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Feb 12 21:13:29 rivo volumio[3272]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28955, instance 2, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp service started and running in background, instance 2 Feb 12 21:13:29 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:29 rivo volumio[3272]: No protocol specified Feb 12 21:13:29 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:29 rivo volumio[3272]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 12 21:13:29 rivo volumio[3272]: cannot open device 'volumioHw': No such device Feb 12 21:13:29 rivo volumio[3272]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Feb 12 21:13:29 rivo volumio[3272]: No protocol specified Feb 12 21:13:29 rivo volumio[3272]: xcb_connection_has_error() returned true Feb 12 21:13:29 rivo volumio[3272]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 12 21:13:29 rivo volumio[3272]: cannot open device 'volumioHw': No such device Feb 12 21:13:29 rivo qobuz-connect[28856]: 20260212 21:13:29.673 [28856.28964] INFO SampleApp: API endpoint invoked: get-display-info Feb 12 21:13:29 rivo qobuz-connect[28856]: 20260212 21:13:29.681 [28856.28964] INFO SampleApp: API endpoint invoked: get-display-info Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp loaded Feb 12 21:13:29 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 12 21:13:29 rivo volumio[3272]: info: Adding Signal Path Element [object Object] Feb 12 21:13:29 rivo volumio[3272]: info: Updating fusiondspeq DSP Signal Path Element Feb 12 21:13:29 rivo volumio[3272]: info: Additional DSP elements updated Feb 12 21:13:29 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:29 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:29 rivo volumio[3272]: info: Updating RAAT Signal Path Feb 12 21:13:29 rivo volumio[3272]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp - ---- installed callbackRead Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp - ---- read samplerate, raw: Feb 12 21:13:29 rivo volumio[3272]: error: FusionDsp - invalid sample rate Feb 12 21:13:29 rivo volumio[3272]: info: FusionDsp - ---- read samplerate, raw: Feb 12 21:13:29 rivo volumio[3272]: error: FusionDsp - invalid sample rate Feb 12 21:13:29 rivo volumio[3272]: error: FusionDsp - WebSocket error: [object Object] Feb 12 21:13:29 rivo sudo[28966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 12 21:13:29 rivo sudo[28966]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:29 rivo sudo[28966]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28968, instance 2, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28975, instance 1, run: true Feb 12 21:13:29 rivo volumio[3272]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28982, instance 2, run: true Feb 12 21:13:29 rivo volumio[3272]: info: camilladsp spawned new process with pid 28989, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 28996, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29003, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29010, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29017, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29024, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29031, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29038, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29045, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29052, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29059, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29066, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29073, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29080, instance 2, run: true Feb 12 21:13:30 rivo mpd[28857]: Feb 12 21:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29087, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29094, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29101, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29108, instance 2, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29115, instance 1, run: true Feb 12 21:13:30 rivo volumio[3272]: info: camilladsp spawned new process with pid 29122, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29129, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29136, instance 2, run: true Feb 12 21:13:31 rivo systemd[1]: Started Music Player Daemon. Feb 12 21:13:31 rivo sudo[28833]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:31 rivo sudo[28784]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29147, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: error: MPD error: The expression evaluated to a falsy value: Feb 12 21:13:31 rivo volumio[3272]: assert.ok(self.idling) Feb 12 21:13:31 rivo volumio[3272]: error: The expression evaluated to a falsy value: Feb 12 21:13:31 rivo volumio[3272]: assert.ok(self.idling) Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29154, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: error: updateQueue error: null Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29161, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29168, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29175, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29182, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29189, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29196, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: RAAT: Requesting Headphone Status Feb 12 21:13:31 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29203, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29210, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29217, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29224, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29231, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29238, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29245, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29252, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29259, instance 1, run: true Feb 12 21:13:31 rivo volumio[3272]: info: RAAT: Requesting Headphone Status Feb 12 21:13:31 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29266, instance 2, run: true Feb 12 21:13:31 rivo volumio[3272]: info: camilladsp spawned new process with pid 29273, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29280, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29287, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29294, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29301, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29310, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29317, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29324, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29331, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29338, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29345, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29352, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29359, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29366, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29373, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29380, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29387, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29394, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29401, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29408, instance 2, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29415, instance 1, run: true Feb 12 21:13:32 rivo volumio[3272]: info: camilladsp spawned new process with pid 29422, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29429, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29436, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29443, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29450, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29457, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29464, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29473, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29480, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29487, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29494, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29501, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29508, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29515, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29522, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29529, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29536, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29543, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29550, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29557, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29564, instance 2, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29571, instance 1, run: true Feb 12 21:13:33 rivo volumio[3272]: info: camilladsp spawned new process with pid 29578, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29585, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29592, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29599, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29606, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29613, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29620, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29627, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29636, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29643, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29650, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29657, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29664, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29671, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29678, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29685, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29692, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29699, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29706, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29713, instance 1, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29720, instance 2, run: true Feb 12 21:13:34 rivo volumio[3272]: info: camilladsp spawned new process with pid 29727, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29734, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29741, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29748, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29755, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29762, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29769, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29776, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29783, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29792, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29799, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29806, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29813, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29820, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29827, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29834, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29841, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29848, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29855, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29862, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29869, instance 1, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29876, instance 2, run: true Feb 12 21:13:35 rivo volumio[3272]: info: camilladsp spawned new process with pid 29883, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29890, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29897, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29904, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29911, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29918, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29925, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29932, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29939, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29946, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29955, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29962, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29969, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29976, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29983, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29990, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 29997, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30004, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30011, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30018, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30025, instance 1, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30032, instance 2, run: true Feb 12 21:13:36 rivo volumio[3272]: info: camilladsp spawned new process with pid 30039, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30046, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30053, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30060, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30067, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30074, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30081, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30088, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30095, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30102, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30109, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30118, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30125, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30132, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30139, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30146, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30153, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30160, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30167, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30174, instance 2, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30181, instance 1, run: true Feb 12 21:13:37 rivo volumio[3272]: info: camilladsp spawned new process with pid 30188, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30195, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30202, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30209, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30216, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30223, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30230, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30237, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30244, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30251, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30258, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30265, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30274, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30281, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30288, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30295, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30302, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30309, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30316, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30323, instance 1, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30330, instance 2, run: true Feb 12 21:13:38 rivo volumio[3272]: info: camilladsp spawned new process with pid 30337, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30344, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30351, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30358, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30365, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30377, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30391, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30403, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30410, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30417, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30424, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30431, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30438, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30447, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30454, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30461, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30468, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30476, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30490, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30502, instance 2, run: true Feb 12 21:13:39 rivo volumio[3272]: info: camilladsp spawned new process with pid 30516, instance 1, run: true Feb 12 21:13:39 rivo volumio[3272]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/fusiondsp/rivo/buster/armhf Feb 12 21:13:39 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:39.918-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30541, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30553, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30568, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30581, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30589, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30596, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30603, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30610, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30617, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30624, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30631, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30638, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30646, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30654, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30661, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30668, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30675, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30682, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30689, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30696, instance 1, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30703, instance 2, run: true Feb 12 21:13:40 rivo volumio[3272]: info: camilladsp spawned new process with pid 30710, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30717, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30724, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30731, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30738, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30745, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30752, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30759, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30766, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30773, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30780, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30787, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30794, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30801, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30810, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30817, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30824, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30831, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30838, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30845, instance 2, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30852, instance 1, run: true Feb 12 21:13:41 rivo volumio[3272]: info: camilladsp spawned new process with pid 30859, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30866, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30873, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30880, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30887, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30894, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30901, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30908, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30915, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30922, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30929, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30936, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30943, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30950, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30957, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30964, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30973, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30980, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30987, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 30994, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 31001, instance 2, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 31008, instance 1, run: true Feb 12 21:13:42 rivo volumio[3272]: info: camilladsp spawned new process with pid 31015, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31022, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31029, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31036, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31043, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31050, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31057, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31064, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31071, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31078, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31085, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31092, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31099, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31106, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31113, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31120, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31127, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31136, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31143, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31150, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31157, instance 2, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31164, instance 1, run: true Feb 12 21:13:43 rivo volumio[3272]: info: camilladsp spawned new process with pid 31171, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31178, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31185, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31192, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31199, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31206, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31213, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31220, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31227, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31234, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31241, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31248, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31255, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31262, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31269, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31276, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31283, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31290, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31301, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31308, instance 1, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31315, instance 2, run: true Feb 12 21:13:44 rivo volumio[3272]: info: camilladsp spawned new process with pid 31322, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31329, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31336, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31343, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31350, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31357, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31364, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31371, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31378, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31385, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31392, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31399, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31406, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31413, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31420, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31427, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31434, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31441, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31448, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31455, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31464, instance 1, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31471, instance 2, run: true Feb 12 21:13:45 rivo volumio[3272]: info: camilladsp spawned new process with pid 31477, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31485, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31492, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31499, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31506, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31513, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31520, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31527, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31534, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31541, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31548, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31555, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31562, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31569, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31576, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31583, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31590, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31597, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31604, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31611, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31620, instance 1, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31627, instance 2, run: true Feb 12 21:13:46 rivo volumio[3272]: info: camilladsp spawned new process with pid 31634, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31641, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31648, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31655, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31662, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31669, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31676, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31683, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31690, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31697, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31704, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31711, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31718, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31725, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31732, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31739, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31746, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31753, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31760, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31767, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31774, instance 1, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31782, instance 2, run: true Feb 12 21:13:47 rivo volumio[3272]: info: camilladsp spawned new process with pid 31790, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31797, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31804, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31811, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31818, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31825, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31832, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31839, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31846, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31853, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31860, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31867, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31874, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31881, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31888, instance 1, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31895, instance 2, run: true Feb 12 21:13:48 rivo volumio[3272]: info: camilladsp spawned new process with pid 31902, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31909, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31917, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31925, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31932, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31939, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31946, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31958, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31976, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31984, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31991, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 31998, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32005, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32012, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32019, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32026, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32033, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32040, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32047, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32055, instance 2, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32062, instance 1, run: true Feb 12 21:13:49 rivo volumio[3272]: info: camilladsp spawned new process with pid 32069, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32076, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32083, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32090, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32099, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32106, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32113, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32120, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32127, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32134, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32141, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32148, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32155, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32162, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32169, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32176, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32183, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32190, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32197, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32204, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32211, instance 2, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32218, instance 1, run: true Feb 12 21:13:50 rivo volumio[3272]: info: camilladsp spawned new process with pid 32225, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32232, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32239, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32246, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32255, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32262, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32269, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32276, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32283, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32290, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32297, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32304, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32311, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32318, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32325, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32332, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32339, instance 2, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32346, instance 1, run: true Feb 12 21:13:51 rivo volumio[3272]: info: camilladsp spawned new process with pid 32353, instance 2, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32360, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32367, instance 2, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32374, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32382, instance 2, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32390, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32397, instance 2, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32404, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/fusiondsp/rivo/buster/armhf Feb 12 21:13:52 rivo volumio[3272]: info: FusionDsp - Stopping FusionDsp service Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp stopping service pid 32397... Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp service terminated, instance 2 Feb 12 21:13:52 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:52.498-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:52 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:52.507-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:52 rivo sudo[32415]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Feb 12 21:13:52 rivo sudo[32415]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 12 21:13:52 rivo systemd[1]: Stopping FusionDsp Daemon... Feb 12 21:13:52 rivo volumio[28629]: Backend configuration: Feb 12 21:13:52 rivo volumio[28629]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Feb 12 21:13:52 rivo volumio[28629]: active_config_txt: null Feb 12 21:13:52 rivo volumio[28629]: camilla_host: 127.0.0.1 Feb 12 21:13:52 rivo volumio[28629]: camilla_port: 9876 Feb 12 21:13:52 rivo volumio[28629]: coeff_dir: /data/INTERNAL/FusionDsp/filters Feb 12 21:13:52 rivo volumio[28629]: config_dir: /data/configuration/audio_interface/fusiondsp Feb 12 21:13:52 rivo volumio[28629]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Feb 12 21:13:52 rivo volumio[28629]: log_file: /tmp/camilladsp.log Feb 12 21:13:52 rivo volumio[28629]: on_get_active_config: null Feb 12 21:13:52 rivo volumio[28629]: on_set_active_config: null Feb 12 21:13:52 rivo volumio[28629]: port: 5011 Feb 12 21:13:52 rivo volumio[28629]: supported_capture_types: null Feb 12 21:13:52 rivo volumio[28629]: supported_playback_types: null Feb 12 21:13:52 rivo volumio[28629]: update_config_symlink: false Feb 12 21:13:52 rivo volumio[28629]: update_config_txt: false Feb 12 21:13:52 rivo volumio[28629]: ======== Running on http://0.0.0.0:5011 ======== Feb 12 21:13:52 rivo volumio[28629]: (Press CTRL+C to quit) Feb 12 21:13:52 rivo volumio[3272]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32420, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32427, instance 1, run: true Feb 12 21:13:52 rivo systemd[1]: fusiondsp.service: Succeeded. Feb 12 21:13:52 rivo systemd[1]: Stopped FusionDsp Daemon. Feb 12 21:13:52 rivo sudo[32415]: pam_unix(sudo:session): session closed for user root Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32435, instance 1, run: true Feb 12 21:13:52 rivo volumio[3272]: info: FusionDsp - Reporting Fusion DSP Disabled Feb 12 21:13:52 rivo volumio[3272]: info: Removing fusiondspeq DSP Signal Path Element Feb 12 21:13:52 rivo volumio[3272]: info: Additional DSP elements updated Feb 12 21:13:52 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:52 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 21:13:52 rivo volumio[3272]: info: Updating RAAT Signal Path Feb 12 21:13:52 rivo volumio[3272]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Feb 12 21:13:52 rivo volumio[3272]: info: camilladsp spawned new process with pid 32442, instance 1, run: true Feb 12 21:13:53 rivo volumio[3272]: info: camilladsp spawned new process with pid 32449, instance 1, run: true Feb 12 21:13:53 rivo volumio[3272]: info: camilladsp spawned new process with pid 32456, instance 1, run: true Feb 12 21:13:53 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:53.176-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:53 rivo volumio[3272]: info: Check plugin dependencies Feb 12 21:13:53 rivo volumio[3272]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 21:13:53 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:53.269-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:53 rivo volumio[3272]: info: Rename folder Feb 12 21:13:53 rivo volumio[3272]: info: Folder /tmp/downloaded_plugin.zip removed Feb 12 21:13:53 rivo volumio5-onboarding[4146]: time=2026-02-12T21:13:53.327-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 12 21:13:53 rivo volumio[3272]: info: Move to category Feb 12 21:13:53 rivo volumio[3272]: info: camilladsp spawned new process with pid 32469, instance 1, run: true Feb 12 21:13:53 rivo volumio[3272]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Feb 12 21:13:53 rivo volumio[3272]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:13:53 rivo volumio[3272]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Feb 12 21:13:53 rivo volumio[3272]: at Process.ChildProcess._handle.onexit (internal/child_process.js:277:19) Feb 12 21:13:53 rivo volumio[3272]: at onErrorNT (internal/child_process.js:472:16) Feb 12 21:13:53 rivo volumio[3272]: at processTicksAndRejections (internal/process/task_queues.js:82:21) { Feb 12 21:13:53 rivo volumio[3272]: errno: -2, Feb 12 21:13:53 rivo volumio[3272]: code: 'ENOENT', Feb 12 21:13:53 rivo volumio[3272]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Feb 12 21:13:53 rivo volumio[3272]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Feb 12 21:13:53 rivo volumio[3272]: spawnargs: [ Feb 12 21:13:53 rivo volumio[3272]: '-p', Feb 12 21:13:53 rivo volumio[3272]: 9876, Feb 12 21:13:53 rivo volumio[3272]: '-o', Feb 12 21:13:53 rivo volumio[3272]: '/tmp/camilladsp.log', Feb 12 21:13:53 rivo volumio[3272]: '-l', Feb 12 21:13:53 rivo volumio[3272]: 'warn', Feb 12 21:13:53 rivo volumio[3272]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Feb 12 21:13:53 rivo volumio[3272]: ] Feb 12 21:13:53 rivo volumio[3272]: } Feb 12 21:13:53 rivo volumio[3272]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 21:13:54 rivo sudo[32486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-12 21:12 Feb 12 21:13:54 rivo sudo[32486]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 02:25:23 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ab3f2fa07b5f7b8b5e7143217bee70a8"