search

QubesOS / qubes-issues

The Qubes OS Project issue tracker
https://www.qubes-os.org/doc/issue-tracking/
533 stars 46 forks source link

Wrong qrexec-client exit code on missing service #9300

Open marmarek opened 2 months ago

marmarek commented 2 months ago

Observation

openQA test in scenario qubesos-4.3-pull-requests-x86_64-system_tests_usbproxy@64bit fails in TC_20_USBProxy_core3_whonix-gateway-17

# test_070_attach_not_installed_front
# error: 

# timestamp 2024-06-12T17:08:30.344538
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/qubesusbproxy/core3ext.py", line 610, in on_device_attach_usb
    await vm.run_service_for_stdio('qubes.USBAttach',
  File "/usr/lib/python3.11/site-packages/qubes/vm/qubesvm.py", line 1579, in run_service_for_stdio
    raise subprocess.CalledProcessError(p.returncode,
subprocess.CalledProcessError: Command 'qubes.USBAttach' returned non-zero exit status 1.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib64/python3.11/contextlib.py", line 81, in inner
    return func(*args, **kwds)
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/qubesusbproxy/tests.py", line 549, in test_070_attach_not_installed_front
    self.loop.run_until_complete(
  File "/usr/lib64/python3.11/asyncio/base_events.py", line 653, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/qubes/devices.py", line 251, in attach
    await self._vm.fire_event_async('device-pre-attach:' + self._bus,
  File "/usr/lib/python3.11/site-packages/qubes/events.py", line 234, in fire_event_async
    effect = task.result()
             ^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/qubesusbproxy/core3ext.py", line 622, in on_device_attach_usb
    raise QubesUSBException(
qubesusbproxy.core3ext.QubesUSBException: Device attach failed: 2024-06-12 13:09:14.062 qrexec-client[109667]: process_io.c:39:handle_vchan_error: Error while vchan send(handle_input stdout), exiting

# system-out: 
[2024-06-12 13:09:14] [   10.374219] qrexec-agent[1247]: 2024-06-12 17:09:18.065 qrexec-agent[1247]: exec.c:657:find_qrexec_service: Service not found: qubes.USBAttach+
[2024-06-12 13:09:14] [   10.374665] qrexec-agent[1247]: 2024-06-12 17:09:18.065 qrexec-agent[1247]: qrexec-agent-data.c:242:handle_new_process_common: failed to spawn process

Test suite description

Test removes /etc/qubes-rpc/qubes.USBAttach and then tries to execute it. It should fail with exit code 127, but as the above message says, it exited with code 1.

Reproducible

Fails since (at least) Build 2024061215-4.3 (current job)

Expected result

Last good: 2024061115-4.3 (or more recent)

Further details

Always latest result in this scenario: latest

marmarek commented 2 months ago

Since this test fails only sometimes, it's likely a race condition. My hypothesis is that qrexec-client fails to send stdin data and exits with code 1, before handling exit code message received from the remote side. If I'm correct, this may also cause loosing some final messages from the service, if the client tried to send something at the same time. Again, if I'm correct, the solution is to handle remaining vchan messages even if sending failed already (but don't try to send any more data, and don't read from stdin anymore).