usb kernel error: string descriptor 0 read error: -110 / can't set config #1, error -110 / ledger blue display freezing

[adrelanos]

Qubes OS version:

R3.2 / R4

Affected TemplateVMs:

debian-9, fedora-25

---

Steps to reproduce the behavior:

start an AppVM
run sudo journalctl -f in AppVM
attach ledger blue to notebook
enter pin on ledger blue display
use qvm-usb to attach ledger blue to an AppVM

Expected behavior:

• no error messages about USB in journal
• ledger blue display not freezing

Actual behavior:

• error messages about USB in journal
• ledger blue display freezing

General notes:

Ledger Blue is working with Debian Linux but freezing when being used with Qubes OS once it gets attached to an AppVM. [ Ledger blue MCU: 3.3 / Secure element: 2.01rgs ]

Freezing meaning that the display (let's say menu but any menu) last image gets frozen. Any keypress on the touchscreen shows no reaction at all. Long power press to turn off is functional. (That shouldn't happen. Even if Qubes OS is an uncommon operating system, it should not be able to crash/freeze ledger blue.)

For comparison, I am also owning a ledger nano s where, which is working, where this issue is not happening. (Restored the same seed on ledger blue that I am also using with ledger nano s.) [ Ledger nano s: secure element 1.3.1 / MCU 1.1) ]

In summary:

• ledger nano s with Debian: working
• ledger nano s with Qubes OS R3.2 / R4: working
• ledger blue with Debian: working
• ledger blue with Qubes OS R3.2 / R4: display freeze bug as described here

Attached below the journalctl log what is happening.

Dec 12 18:45:03 private-crypto-ledger qrexec-agent[656]: executed root:QUBESRPC qubes.USBAttach dom0 pid 3205
Dec 12 18:45:03 private-crypto-ledger su[3205]: Successful su for root by root
Dec 12 18:45:03 private-crypto-ledger su[3205]: + ??? root:root
Dec 12 18:45:03 private-crypto-ledger su[3205]: pam_unix(su:session): session opened for user root by (uid=0)
Dec 12 18:45:03 private-crypto-ledger systemd[1]: Created slice User Slice of root.
Dec 12 18:45:03 private-crypto-ledger systemd[1]: Starting User Manager for UID 0...
Dec 12 18:45:03 private-crypto-ledger systemd-logind[570]: New session c8 of user root.
Dec 12 18:45:03 private-crypto-ledger systemd[1]: Started Session c8 of user root.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on GnuPG cryptographic agent and passphrase cache.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Reached target Paths.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on GnuPG network certificate management daemon.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on GnuPG cryptographic agent (access for web browsers).
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Reached target Timers.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Starting D-Bus User Message Bus Socket.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Listening on D-Bus User Message Bus Socket.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Reached target Sockets.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Reached target Basic System.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Reached target Default.
Dec 12 18:45:03 private-crypto-ledger systemd[3206]: Startup finished in 16ms.
Dec 12 18:45:03 private-crypto-ledger systemd[1]: Started User Manager for UID 0.
Dec 12 18:45:04 private-crypto-ledger qubes.USBAttach-dom0[3241]: /usr/lib/qubes/usb-import: 37: [: Illegal number: sta
Dec 12 18:45:04 private-crypto-ledger kernel: vhci_hcd vhci_hcd: pdev(0) rhport(0) sockfd(0)
Dec 12 18:45:04 private-crypto-ledger kernel: vhci_hcd vhci_hcd: devid(262164) speed(2) speed_str(full-speed)
Dec 12 18:45:04 private-crypto-ledger kernel: usb 2-1: new full-speed USB device number 6 using vhci_hcd
Dec 12 18:45:04 private-crypto-ledger kernel: usb 2-1: SetAddress Request (6) to port 0
Dec 12 18:45:04 private-crypto-ledger kernel: usb 2-1: config index 0 descriptor too short (expected 41, got 9)
Dec 12 18:45:04 private-crypto-ledger kernel: usb 2-1: config 1 has 0 interfaces, different from the descriptor's value: 1
Dec 12 18:45:09 private-crypto-ledger kernel: vhci_hcd: dequeue a urb ffff8800f0335cc0
Dec 12 18:45:09 private-crypto-ledger kernel: vhci_hcd: device ffff8800f130a288 seems to be still connected
Dec 12 18:45:09 private-crypto-ledger kernel: vhci_hcd: unlink->seqnum 75
Dec 12 18:45:09 private-crypto-ledger kernel: vhci_hcd: urb->status -104
Dec 12 18:45:14 private-crypto-ledger kernel: vhci_hcd: dequeue a urb ffff8800f0335cc0
Dec 12 18:45:14 private-crypto-ledger kernel: vhci_hcd: device ffff8800f130a288 seems to be still connected
Dec 12 18:45:14 private-crypto-ledger kernel: vhci_hcd: unlink->seqnum 77
Dec 12 18:45:14 private-crypto-ledger kernel: vhci_hcd: urb->status -104
Dec 12 18:45:14 private-crypto-ledger kernel: usb 2-1: string descriptor 0 read error: -110
Dec 12 18:45:14 private-crypto-ledger kernel: usb 2-1: New USB device found, idVendor=2c97, idProduct=0000
Dec 12 18:45:14 private-crypto-ledger kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 12 18:45:14 private-crypto-ledger mtp-probe[3351]: checking bus 2, device 6: "/sys/devices/platform/vhci_hcd/usb2/2-1"
Dec 12 18:45:14 private-crypto-ledger mtp-probe[3351]: bus: 2, device: 6 was not an MTP device
Dec 12 18:45:19 private-crypto-ledger kernel: vhci_hcd: dequeue a urb ffff8800f0335e40
Dec 12 18:45:19 private-crypto-ledger kernel: vhci_hcd: device ffff8800f130a288 seems to be still connected
Dec 12 18:45:20 private-crypto-ledger kernel: vhci_hcd: unlink->seqnum 79
Dec 12 18:45:20 private-crypto-ledger kernel: vhci_hcd: urb->status -104
Dec 12 18:45:20 private-crypto-ledger kernel: usb 2-1: can't set config #1, error -110
Dec 12 18:45:20 private-crypto-ledger su[3205]: pam_unix(su:session): session closed for user root
Dec 12 18:45:20 private-crypto-ledger qrexec-agent[656]: send exit code 0
Dec 12 18:45:20 private-crypto-ledger qrexec-agent[656]: pid 3205 exited with 0
Dec 12 18:45:20 private-crypto-ledger qrexec-agent[656]: eintr
Dec 12 18:45:30 private-crypto-ledger kernel: vhci_hcd: connection closed
Dec 12 18:45:30 private-crypto-ledger kernel: vhci_hcd: stop threads
Dec 12 18:45:30 private-crypto-ledger kernel: vhci_hcd: release socket
Dec 12 18:45:30 private-crypto-ledger kernel: vhci_hcd: disconnect device
Dec 12 18:45:30 private-crypto-ledger kernel: usb 2-1: USB disconnect, device number 6
Dec 12 18:45:30 private-crypto-ledger systemd-logind[570]: Removed session c8.
Dec 12 18:45:30 private-crypto-ledger systemd[1]: Stopping User Manager for UID 0...
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Stopped target Default.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Stopped target Basic System.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Stopped target Paths.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Stopped target Timers.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Stopped target Sockets.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed GnuPG cryptographic agent and passphrase cache.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed D-Bus User Message Bus Socket.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed GnuPG cryptographic agent (access for web browsers).
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed GnuPG network certificate management daemon.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Reached target Shutdown.
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Starting Exit the Session...
Dec 12 18:45:30 private-crypto-ledger systemd[3206]: Received SIGRTMIN+24 from PID 3382 (kill).
Dec 12 18:45:30 private-crypto-ledger systemd[1]: Stopped User Manager for UID 0.
Dec 12 18:45:30 private-crypto-ledger systemd[1]: Removed slice User Slice of root.