Hi @qun, are you using USB-C for the connection?
I know this is an old thread, but I’m getting the same error here for a hardware key USB stick (that ones used for software licensing). The behavior is the same when using both command line and device widget, when the error is shown as a popup notification. I’m posting since this may help others to troubleshoot similar issues.
The point is, the error occurs only when the USB device was connected to the ports of a USB-C hub. When trying to use the device on regulara regular USB port from the notebook, the error does not happen. (Though I still don’t manage to use the hardware in the Windows VM, in Windows Device Manager, the USB ports are listed as “XENBUS VBD” and “XENBUS VIF”)
[user@dom0 ~]$ qvm-usb
BACKEND:DEVID DESCRIPTION USED BY
sys-usb:2-1 Vimicro_Corp._Lenovo_FHD_Webcam_Lenovo_FHD_Webcam_Audio
sys-usb:2-2.3 PROTEQ_ltda_PROTEQ_USB
sys-usb:2-6 Telink_Wireless_Receiver
sys-usb:2-7 8087_0a2b
sys-usb:2-8 SunplusIT_Inc_Integrated_Camera
sys-usb:2-9 138a_0097_570c8cb91475
[user@dom0 ~]$ qvm-usb attach win7 sys-usb:2-2.3 --verbose
Device attach failed: Attach timeout, check kernel log for details. /usr/lib/qubes/usb-import: line 1: hostname: not foundVM: "" File: "/usr/lib/qubes/usb-import" Version Control: https://github.com/QubesOS/qubes-app-linux-usb-proxy/blob/master/src/usb-import
I searched the logs to troubleshoot but have no clues on what’s happening:
/var/log/xen/console/guest-sys-usb.log
[2022-09-10 21:17:02] [11394.245736] audit: type=1100 audit(1662855422.079:480): pid=9413 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:authentication grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:02] [11394.246095] audit: type=1103 audit(1662855422.079:481): pid=9413 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:setcred grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:02] [11394.274152] audit: type=1130 audit(1662855422.107:482): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir@0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:02] [11394.284452] audit: type=1101 audit(1662855422.117:483): pid=9415 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:02] [11394.285316] audit: type=1103 audit(1662855422.118:484): pid=9415 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:setcred grantors=? acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[2022-09-10 21:17:02] [11394.285701] audit: type=1006 audit(1662855422.119:485): pid=9415 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=8 res=1
[2022-09-10 21:17:02] [11394.285778] audit: type=1300 audit(1662855422.119:485): arch=c000003e syscall=1 success=yes exit=1 a0=7 a1=7ffeb3813360 a2=1 a3=7ffeb3813077 items=0 ppid=1 pid=9415 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=8 comm="(systemd)" exe="/usr/lib/systemd/systemd" key=(null)
[2022-09-10 21:17:02] [11394.286006] audit: type=1327 audit(1662855422.119:485): proctitle="(systemd)"
[2022-09-10 21:17:02] [11394.288612] audit: type=1105 audit(1662855422.122:486): pid=9415 uid=0 auid=0 ses=8 msg='op=PAM:session_open grantors=pam_selinux,pam_selinux,pam_loginuid,pam_namespace,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:02] [11394.295029] audit: type=1334 audit(1662855422.128:487): prog-id=156 op=LOAD
[2022-09-10 21:17:02] [11394.668433] usbip-host 2-2.3: usbip-host: register new device (bus 2 dev 5)
[2022-09-10 21:17:02] [11394.677535] usbip-host 2-2.3: stub up
[2022-09-10 21:17:07] [11399.907017] usbip-host 2-2.3: recv a header, 0
[2022-09-10 21:17:08] [11400.162760] usbip-host 2-2.3: reset low-speed USB device number 5 using xhci_hcd
[2022-09-10 21:17:08] [11400.438398] usbip-host 2-2.3: device reset
[2022-09-10 21:17:08] [11400.722640] kauditd_printk_skb: 60 callbacks suppressed
[2022-09-10 21:17:08] [11400.722643] audit: type=1106 audit(1662855428.555:520): pid=9413 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:08] [11400.722731] audit: type=1104 audit(1662855428.555:521): pid=9413 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:setcred grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:18] [11410.772310] audit: type=1104 audit(1662855438.605:522): pid=9418 uid=0 auid=0 ses=8 msg='op=PAM:setcred grantors=? acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[2022-09-10 21:17:18] [11410.776662] audit: type=1131 audit(1662855438.609:523): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user@0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:18] [11410.808878] audit: type=1131 audit(1662855438.640:524): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir@0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:32] [11424.619752] audit: type=1131 audit(1662855452.452:525): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[2022-09-10 21:17:32] [11424.642619] audit: type=1334 audit(1662855452.476:526): prog-id=0 op=UNLOAD
[2022-09-10 21:17:32] [11424.642646] audit: type=1334 audit(1662855452.476:527): prog-id=0 op=UNLOAD
[2022-09-10 21:18:13] [11465.270521] xen:grant_table: g.e. 0x1327 still pending
[2022-09-10 21:18:13] [11465.270577] xen:grant_table: g.e. 0x1326 still pending
[2022-09-10 21:18:13] [11465.270612] xen:grant_table: g.e. 0x1325 still pending
[2022-09-10 21:18:13] [11465.270646] xen:grant_table: g.e. 0x1323 still pending
[2022-09-10 21:18:13] [11465.270680] xen:grant_table: g.e. 0x12fe still pending
[2022-09-10 21:18:13] [11465.270714] xen:grant_table: g.e. 0x12fd still pending
[2022-09-10 21:18:13] [11465.270748] xen:grant_table: g.e. 0x12fc still pending
[2022-09-10 21:18:13] [11465.270782] xen:grant_table: g.e. 0x12fb still pending
[2022-09-10 21:18:13] [11465.270815] xen:grant_table: g.e. 0x12fa still pending
[2022-09-10 21:18:13] [11465.270849] xen:grant_table: g.e. 0x12f9 still pending
[2022-09-10 21:18:13] [11465.270885] xen:grant_table: g.e. 0x12f8 still pending
[2022-09-10 21:18:13] [11465.270918] xen:grant_table: g.e. 0x12f7 still pending
[2022-09-10 21:18:13] [11465.270952] xen:grant_table: g.e. 0x12f6 still pending
[2022-09-10 21:18:13] [11465.270986] xen:grant_table: g.e. 0x12f5 still pending
[2022-09-10 21:18:13] [11465.271019] xen:grant_table: g.e. 0x12f4 still pending
[2022-09-10 21:18:13] [11465.271053] xen:grant_table: g.e. 0x12f3 still pending
[2022-09-10 21:18:13] [11465.271087] xen:grant_table: g.e. 0x12f2 still pending
[2022-09-10 21:18:13] [11465.271121] xen:grant_table: g.e. 0x12f1 still pending
[2022-09-10 21:18:13] [11465.271155] xen:grant_table: g.e. 0x12f0 still pending
[2022-09-10 21:18:13] [11465.271189] xen:grant_table: g.e. 0x12ef still pending
[2022-09-10 21:18:13] [11465.271222] xen:grant_table: g.e. 0x12ee still pending
[2022-09-10 21:18:13] [11465.271256] xen:grant_table: g.e. 0x12ed still pending
[2022-09-10 21:18:13] [11465.271289] xen:grant_table: g.e. 0x12ec still pending
dmesg on dom0:
[12036.808790] audit: type=1101 audit(1662856010.868:4399): pid=23053 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_permit acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12042.814502] audit: type=1100 audit(1662856016.873:4400): pid=23054 uid=1000 auid=1000 ses=2 msg='op=PAM:authentication grantors=pam_localuser acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12042.815614] audit: type=1101 audit(1662856016.875:4401): pid=23054 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_permit acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12048.811538] audit: type=1100 audit(1662856022.870:4402): pid=23059 uid=1000 auid=1000 ses=2 msg='op=PAM:authentication grantors=pam_localuser acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12048.811834] audit: type=1101 audit(1662856022.870:4403): pid=23059 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_permit acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12054.813928] audit: type=1100 audit(1662856028.873:4404): pid=23060 uid=1000 auid=1000 ses=2 msg='op=PAM:authentication grantors=pam_localuser acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12054.814118] audit: type=1101 audit(1662856028.873:4405): pid=23060 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_permit acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12060.822679] audit: type=1100 audit(1662856034.882:4406): pid=23062 uid=1000 auid=1000 ses=2 msg='op=PAM:authentication grantors=pam_localuser acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12060.822871] audit: type=1101 audit(1662856034.882:4407): pid=23062 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_permit acct="root" exe="/usr/sbin/userhelper" hostname=? addr=? terminal=? res=success'
[12066.412472] audit: type=1101 audit(1662856040.471:4408): pid=23068 uid=1000 auid=1000 ses=2 msg='op=PAM:accounting grantors=pam_unix acct="henrique" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/9 res=success'
[12066.413237] audit: type=1123 audit(1662856040.472:4409): pid=23068 uid=1000 auid=1000 ses=2 msg='cwd="/home/henrique" cmd="dmesg" exe="/usr/bin/sudo" terminal=pts/9 res=success'
[12066.414395] audit: type=1110 audit(1662856040.473:4410): pid=23068 uid=1000 auid=1000 ses=2 msg='op=PAM:setcred grantors=pam_env,pam_unix acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/9 res=success'
[12066.425030] audit: type=1105 audit(1662856040.484:4411): pid=23068 uid=1000 auid=1000 ses=2 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/9 res=success'
/var/log/xen/console/guest-win7-dm.log:
[2022-09-10 21:17:01] 2022-09-11 00:17:01.929 qrexec-agent[509]: qrexec-agent-data.c:244:handle_new_process_common: executed: root:QUBESRPC qubes.USBAttach dom0 (pid 512)
[2022-09-10 21:17:02] vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(0)
[2022-09-10 21:17:02] vhci_hcd vhci_hcd.0: devid(131077) speed(1) speed_str(low-speed)
[2022-09-10 21:17:02] vhci_hcd vhci_hcd.0: Device attached
[2022-09-10 21:17:02] usb 1-1: new low-speed USB device number 2 using vhci_hcd
[2022-09-10 21:17:02] usb 1-1: SetAddress Request (2) to port 0
[2022-09-10 21:17:02] usb 1-1: config index 0 descriptor too short (expected 9, got 0)
[2022-09-10 21:17:02] usb 1-1: can't read configurations, error -22
[2022-09-10 21:17:03] usb 1-1: new low-speed USB device number 3 using vhci_hcd
[2022-09-10 21:17:03] usb 1-1: SetAddress Request (3) to port 0
[2022-09-10 21:17:03] usb 1-1: config index 0 descriptor too short (expected 9, got 0)
[2022-09-10 21:17:03] usb 1-1: can't read configurations, error -22
[2022-09-10 21:17:03] usb usb1-port1: attempt power cycle
[2022-09-10 21:17:03] usb 1-1: new low-speed USB device number 4 using vhci_hcd
[2022-09-10 21:17:03] usb 1-1: SetAddress Request (4) to port 0
[2022-09-10 21:17:03] usb 1-1: device descriptor read/all, error 0
[2022-09-10 21:17:03] usb 1-1: new low-speed USB device number 5 using vhci_hcd
[2022-09-10 21:17:03] usb 1-1: SetAddress Request (5) to port 0
[2022-09-10 21:17:03] usb 1-1: device descriptor read/all, error 0
[2022-09-10 21:17:03] usb usb1-port1: unable to enumerate USB device
[2022-09-10 21:17:07] vhci_hcd: connection closed
[2022-09-10 21:17:07] vhci_hcd: stop threads
[2022-09-10 21:17:07] vhci_hcd: release socket
[2022-09-10 21:17:07] vhci_hcd: disconnect device
[2022-09-10 21:17:08] 2022-09-11 00:17:08.647 qrexec-agent[509]: qrexec-agent-data.c:272:handle_new_process_common: pid 512 exited with 1
Versions: