[R4.3-rc2] sys-usb stopped working after dist-upgrade

User Support Testing Release
1

I have upgraded to 4.3-rc2 recently following the procedure from the docs and have seen the following odd behaviours with sys-usb:

  • sys-usb is not starting automatically anymore, although “Start qube automatically on boot” checkbox is checked (as expected, since it was starting previously to the upgrade)
  • when trying to start it manually, the VM is stopped after ~120 s due to a timeout
  • the USB mouse/keyboard are no longer linked to sys-usb, since I can use them without the VM being run
  • if I try to run the sys-usb VM manually, then the USB mouse/keyboard are no longer available after the timeout

Other system qubes which are marked to autostart are working well, such as sys-net and sys-firewall. sys-usb is based on the same template default-dvm as sys-firewall, so it is not a issue from its template. Both VMs are using the same kernel as well, the one installed by the dist-upgrade. sys-usb was not created manually, it was created by the r4.2 installer.

/var/log/qubes/qrexec.sys-usb.log:

2025-09-28 10:51:41.964 qrexec-daemon[20337]: vchan_timeout.c:46:qubes_wait_for_vchan_connection_with_timeout: vchan connection timeout 2025-09-28 10:51:41.965 qrexec-daemon[20337]: qrexec-daemon.c:399:init: qrexec connection timeout

/var/log/qubes/guid.sys-usb.log:

Icon size: 128x128
Falling back to setting _NET_WM_USER_TIME on the root window
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters...
reloading X server parameters.../
reloading X server parameters...
libvchan_is_eof
Icon size: 128x128
Falling back to setting _NET_WM_USER_TIME on the root window
domain dead
Failed to connect to gui-agent

The dist-upgrade process was performed almost with no errors, starting from 4.2.4. The only troubles I’ve found were that the --all-pre-reboot and --all-post-reboot procedures have failed when they tried to update the Windows VMs (comprehensively), so I performed each of the stages 1-6 one at a time.

2

What’s the template of your default-dvm?
Try to increase the qrexec_timeout of your sys-usb (e.g. 600 s) qube and start it.
You can do it in dom0 terminal:

qvm-prefs sys-usb qrexec_timeout 600

You can check the sys-usb log to see why it fails to start in /var/log/xen/console/guest-sys-usb.log file in dom0.

3

Thank you!

  • Increasing the qrexec_timeout has not worked
  • I figured out the vchan client was disconnected according to the logs.
  • I have not changed the template, it was using fedora-41-xfce as before the upgrade in default-dvm
  • I think the only thing that changed was the VM kernel version that was changed in the dist upgrade.
  • Tried updating to the latest kernel and using it for the sys-usb VM (6.15.10-1.fc41), no effect. Tried the kernel that was being used before (6.12.47-1.fc37), the behaviour is the same.
  • When I remove the passthrough of the PCI-USB device, the sys-usb VM runs normally without the vchan and qrexec timeouts (got the idea from a similar error as in this thread for sys-firewall)
  • The system is a Thinkpad X270, if this may affect the behaviour
  • After booting, journalctl -x | grep sys-usb does not generate any lines… it seems the VM is not being started.

/var/log/xen/console/guest-sys-usb.log has only one entry, which is Logfile Opened.

/var/log/xen/console/guest-sys-usb-dm.log has more info, these are the last lines:

[2025-09-28 09:58:45] Logfile Opened
...
[2025-09-29 22:19:39] ==== Press enter for shell ====
[2025-09-29 22:19:39] + read
[2025-09-29 22:19:39] + vchan-socket-proxy '--mode=server' '--reconnect-marker=1' --verbose 0 device-model/23/qmp-vchan /tmp/qemu.qmp
[2025-09-29 22:19:39] qubes_gui/init: 574
[2025-09-29 22:19:39] qubes_gui/init: 583
[2025-09-29 22:19:39] qubes_gui/init: 586
[2025-09-29 22:19:39] qubes_gui/init[613]: version sent, waiting for xorg conf
[2025-09-29 22:19:39] from-unix: {"QMP": {"version": {"qemu": {"micro": 2, "minor": 0, "major": 9}, "package": ""}, "capabilities": ["oob"]}}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] wrote 110 bytes to vchan
[2025-09-29 22:19:39] from-vchan: 
[2025-09-29 22:19:39] {"return": {}}

[2025-09-29 22:19:39] from-vchan: {"execute":"qmp_capabilities","id":2020372737}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] from-unix: {"return": {}, "id": 2020372737}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] wrote 34 bytes to vchan
[2025-09-29 22:19:39] from-vchan: {"execute":"device_add","id":2020372736,"arguments":{"driver":"xen-pci-passthrough","id":"pci-pt-00_14.0","hostaddr":"0000:00:14.0"}}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] [00:06.0] xen_pt_realize: Assigning real physical device 00:14.0 to devfn 0x30
[2025-09-29 22:19:39] [00:06.0] xen_pt_register_regions: IO region 0 registered (size=0x00010000 base_addr=0xe1220000 type: 0x4)
[2025-09-29 22:19:39] [00:06.0] xen_pt_config_reg_init: Offset 0x0006 mismatch! Emulated=0x0010, host=0x0290, syncing to 0x0290.
[2025-09-29 22:19:39] [00:06.0] xen_pt_config_reg_init: Offset 0x0010 mismatch! Emulated=0x0000, host=0xe1220004, syncing to 0xe1220004.
[2025-09-29 22:19:39] [00:06.0] xen_pt_config_reg_init: Offset 0x0072 mismatch! Emulated=0x0000, host=0x01c2, syncing to 0x0002.
[2025-09-29 22:19:39] [00:06.0] xen_pt_pm_ctrl_reg_init_off: PCI power management control passthrough is off
[2025-09-29 22:19:39] [00:06.0] xen_pt_config_reg_init: Offset 0x0082 mismatch! Emulated=0x0000, host=0x0086, syncing to 0x0080.
[2025-09-29 22:19:39] [00:06.0] xen_pt_pci_intx: intx=1
[2025-09-29 22:19:39] [00:06.0] xen_pt_realize: Real physical device 00:14.0 registered successfully
[2025-09-29 22:19:39] from-unix: {"return": {}, "id": 2020372736}
...
[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] wrote 34 bytes to vchan
[2025-09-29 22:19:39] from-vchan: {"execute":"query-pci","id":2020372738}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] from-unix: {"return": [{"bus": 0, "devices": [{"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 0, "class_info": {"class": 1536, "desc": "Host bridge"}, "id": {"device": 4663, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 1537, "desc": "ISA bridge"}, "id": {"device": 28672, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 257, "desc": "IDE controller"}, "id": {"device": 28688, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 1, "regions": [{"bar": 4, "size": 16, "address": -1, "type": "io"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 1, "class_info": {"class": 1664, "desc": "Bridge"}, "id": {"device": 28947, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 3, "regions": []}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 2, "class_info": {"class": 65408}, "id": {"device": 1, "subsystem-vendor": 22611, "vendor": 22611, "subsystem": 1}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": true, "mem_type_64": false, "bar": 1, "size": 16777216, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 3, "class_info": {"class": 256, "desc": "SCSI controller"}, "id": {"device": 18, "subsystem-vendor": 0, "vendor": 4096, "subsystem": 4096}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": false, "mem_type_64": false, "bar": 1, "size": 1024, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 8192, "address": -1, "type": "memory"}]}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 4, "class_info": {"class": 768, "desc": "VGA controller"}, "id": {"device": 4369, "subsystem-vendor": 6900, "vendor": 4660, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": true, "mem_type_64": false, "bar": 0, "size": 16777216, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 4096, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 6, "size": 65536, "address": -1, "type": "memory"}]}, {"irq_pin": 4, "bus": 0, "qdev_id": "ehci", "irq": 0, "slot": 5, "class_info": {"class": 3075, "desc": "USB controller"}, "id": {"device": 9421, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": false, "mem_type_64": false, "bar": 0, "size": 4096, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "pci-pt-00_14.0", "irq": 0, "slot": 6, "class_info": {"class": 0}, "id": {"device": 40239, "subsystem-vendor": 0, "vendor": 32902, "subsystem": 0}, "function": 0, "regions": [{"prefetch": false, "mem_type_64": true, "bar": 0, "size": 65536, "address": -1, "type": "memory"}]}]}], "id": 2020372738}

[2025-09-29 22:19:39] 
[2025-09-29 22:19:39] wrote 2048 bytes to vchan
[2025-09-29 22:19:39] wrote 973 bytes to vchan
[2025-09-29 22:19:39] vchan client disconnected

**

Now I’m getting a new error after I removed PCI-USB from passthrough and added it again in the devices list, but it seems to be unrelated to the errors above, so it’s maybe subject for a new thread or even a bug report. Now, when trying to start sys-usb manually from Qubes Manager, I get a pop-up with a message like “no response from qubesd”. Journalctl reveals that the Qubes API expects ASCII encoding while some parameter in the sys-usb start command payload seems to be UTF-8 now. When I installed Qubes 4.2, I selected pt-BR as the locale. I couldn’t revert this and this is where I am now.

sudo journalctl -x -e

set 29 22:39:32 dom0 qubesd[2690]: INFO: vm.sys-usb: Starting qube sys-usb
set 29 22:39:33 dom0 lvm[1247]: No longer monitoring thin pool qubes_dom0-vm--pool-tpool.
set 29 22:39:33 dom0 lvm[1247]: Monitoring thin pool qubes_dom0-vm--pool-tpool.
set 29 22:39:33 dom0 lvm[1247]: No longer monitoring thin pool qubes_dom0-vm--pool-tpool.
set 29 22:39:33 dom0 lvm[1247]: Monitoring thin pool qubes_dom0-vm--pool-tpool.
set 29 22:39:34 dom0 virtxend[3092]: erro interno: Falha ao redefinir o dispositivo de PCI 0000:00:14.0: não há nenhuma redefinição de FLR, PM ou redefinição de bus disponível
set 29 22:39:34 dom0 virtxend[3092]: Falha ao redefinir o dispositivo de PCI: erro interno: Falha ao redefinir o dispositivo de PCI 0000:00:14.0: não há nenhuma redefinição de FLR, PM ou redefinição de bus disponível
set 29 22:39:34 dom0 qubesd[2690]: ERROR: vm.sys-usb: Start failed: erro interno: Falha ao redefinir o dispositivo de PCI 0000:00:14.0: não há nenhuma redefinição de FLR, PM ou redefinição de bus disponível
set 29 22:39:34 dom0 qubesd[2690]: ERROR: unhandled exception while calling src=b'dom0' meth=b'admin.vm.Start' dest=b'sys-usb' arg=b'' len(untrusted_payload)=0
set 29 22:39:34 dom0 qubesd[2690]: Traceback (most recent call last):
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1468, in start
set 29 22:39:34 dom0 qubesd[2690]:     self.libvirt_domain.createWithFlags(
set 29 22:39:34 dom0 qubesd[2690]:     ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
set 29 22:39:34 dom0 qubesd[2690]:         libvirt.VIR_DOMAIN_START_PAUSED
set 29 22:39:34 dom0 qubesd[2690]:         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:     )
set 29 22:39:34 dom0 qubesd[2690]:     ^
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/app.py", line 107, in wrapper
set 29 22:39:34 dom0 qubesd[2690]:     return getattr(self._vm, attrname)(*args, **kwargs)
set 29 22:39:34 dom0 qubesd[2690]:            ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib64/python3.13/site-packages/libvirt.py", line 1415, in createWithFlags
set 29 22:39:34 dom0 qubesd[2690]:     raise libvirtError('virDomainCreateWithFlags() failed')
set 29 22:39:34 dom0 qubesd[2690]: libvirt.libvirtError: erro interno: Falha ao redefinir o dispositivo de PCI 0000:00:14.0: não há nenhuma redefinição de FLR, PM ou redefinição de bus disponível
set 29 22:39:34 dom0 qubesd[2690]: During handling of the above exception, another exception occurred:
set 29 22:39:34 dom0 qubesd[2690]: Traceback (most recent call last):
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/api/__init__.py", line 339, in respond
set 29 22:39:34 dom0 qubesd[2690]:     response = await self.mgmt.execute(
set 29 22:39:34 dom0 qubesd[2690]:                ^^^^^^^^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:         untrusted_payload=untrusted_payload
set 29 22:39:34 dom0 qubesd[2690]:         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:     )
set 29 22:39:34 dom0 qubesd[2690]:     ^
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/api/admin.py", line 958, in vm_start
set 29 22:39:34 dom0 qubesd[2690]:     await self.dest.start()
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/vm/dispvm.py", line 661, in start
set 29 22:39:34 dom0 qubesd[2690]:     await super().start(**kwargs)
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/vm/qubesvm.py", line 1494, in start
set 29 22:39:34 dom0 qubesd[2690]:     await self.fire_event_async(
set 29 22:39:34 dom0 qubesd[2690]:         "domain-start-failed", reason=str(exc)
set 29 22:39:34 dom0 qubesd[2690]:     )
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/events.py", line 234, in fire_event_async
set 29 22:39:34 dom0 qubesd[2690]:     sync_effects, async_effects = self._fire_event(
set 29 22:39:34 dom0 qubesd[2690]:                                   ~~~~~~~~~~~~~~~~^
set 29 22:39:34 dom0 qubesd[2690]:         event, kwargs, pre_event=pre_event
set 29 22:39:34 dom0 qubesd[2690]:         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:     )
set 29 22:39:34 dom0 qubesd[2690]:     ^
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/events.py", line 169, in _fire_event
set 29 22:39:34 dom0 qubesd[2690]:     effect = func(self, event, **kwargs)
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/api/admin.py", line 85, in vm_handler
set 29 22:39:34 dom0 qubesd[2690]:     self.send_event(subject, event, **kwargs)
set 29 22:39:34 dom0 qubesd[2690]:     ~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]:   File "/usr/lib/python3.13/site-packages/qubes/api/__init__.py", line 441, in send_event
set 29 22:39:34 dom0 qubesd[2690]:     self.transport.write("{}\0{}\0".format(k, str(v)).encode("ascii"))
set 29 22:39:34 dom0 qubesd[2690]:                          ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^
set 29 22:39:34 dom0 qubesd[2690]: UnicodeEncodeError: 'ascii' codec can't encode character '\xe3' in position 76: ordinal not in range(128)
4

PCI troubleshooting — Qubes OS Documentation

5

Good, I was focusing on the ascii encoding exception.
I added the options no-strict-reset and permissive to the sys-usb VM and now I’m getting the libvirt error “XML Error: Hostdev already exists in the domain configuration, see /var/log/libvirt/libxl/libxl-driver.log”, while the log file does not contain any information related to this command (all entries were from the system startup).

I tried to find out how to solve this that would be an error in the domain declaration for libvirt but could not find how. So I deleted the sys-usb and recreated using the Salt formula. I think the problem was that somehow the PCI device was attached twice to sys-usb.

Now I’m back to the point where the vchan client disconnected message appears in /var/log/xen/console/guest-sys-usb-dm.log and after that the VM is stopped after the configured qrexec timeout is reached. I don’t know what could be interrupting vchan. I’ve checked the qrexec policies and they are allowing qubes.InputKeyboard and qubes.InputMourse for sys-usb.

6

vchan client disconnected message in the sys-usb-dm log is expected.
Check the hypervisor log for errors:

/var/log/xen/console/hypervisor.*
7

hypervisor.log also shows nothing, its last entry is from boot time, not related to qvm-start sys-usb. It seems to be something similar to this issue, I tried tail -F /var/log/xen/console/*.log while starting sys-usb up and no relevant information pops out. Tried the same with tail -F /var/log/qubes/*.log and the only messages that appear are the qrexec and vchan timeouts, 120 s after the start command. Also tried increasing the VM memory, no effect.

Now I could find a “failure” there as xen be core: xs_mkdir device-model/29/backends/vkbd: failed. But it seems to me this is not important.

guest-sys-usb-dm.log (43.4 KB)

8

Try to install a clean template from repository and use it as a template for sys-usb for a test.

9

Yes, good idea. The behavior is the same. I was using te default fedora-42-xfce disposable template before, then installed debian-13-xfce, created a disposable template from it and used as template por sys-usb. The messages in the logs remain the same.

10

What kernel is set for sys-usb? if there are no new messages in hypervisor.log nor guest-sys-usb.log (besides “Logfile opened”), you can try adding earlyprintk=xen to kernelopts property and see if that helps getting some more info.

11

I have tried with kernels 6.12.47-1.fc41, 6.15.10-1.fc41 and 6.16.8-1.fc41, with the same behaviour.

Setting the option with qvm-prefs --set sys-usb kernelopts 'earlyprint=xen' did not produce any additional inputs in /var/log/xen/console/*.log nor /var/log/qubes/*.log files.

I have also tried to run in debug mode, the only entries in the console window that is opened are the first two lines where the machine UUID is printed.

12

it’s earlyprintk=xen, not earlyprint=xen

13

Ah sorry, that’s what I did. I made a mistake while typing here in the forum.