[VisionFive 2] USB: keyboard and mouse do not work if both connected

[X512]

This is hrev57062.

Only keyboard or only mouse connected works, but not together. Connecting multiple USB mass storage devices (3 USB drives and one mouse) works. If MSI-X is not enabled for XHCI, one of 4 USB ports (upper left) is not working.

USB support is implemented with VL805 chip that is connected to PCIe bus and provides 4 USB ports version 2 or 3. It implements XHCI interface and have 5 internal USB ports. Port 1 is connected to internal USB 2 hub that is used for USB 2 devices support. Ports 2-5 are USB 3 ports and connected to external USB ports 1-4.

Problems summary with VL805 chip:

1. Interrupt endpoints with 2 or more devices at the same time is not working. Bulk endpoint work fine with USB 2 mode (mouse and 3 USB mass storage configuration work fine).
2. Only 2 of 4 USB 3 ports are powered on (ports 2, 4: OK, ports 3, 5: not working).
3. USB Mass storage devices in USB 3 mode work unstable and trigger errors "Babble detected", "Device FIFO overrun".

Problem 1 syslog:

usb hub 8: port 1: new device connected
usb_hid: no handlers for hid device
usb_audio:05.24.673:init_driver::ver.0.0.5
usb_hid: keyboard device unhandled control 0x00002710
usb error control pipe 9: timeout waiting for queued request to complete
usb xhci 0: transfer error on slot 1 endpoint 1: Length invalid
usb error xhci 0: TRB 0x4124d0a0 was not found in the endpoint!
usb error hub 8: error updating port status
usb error control pipe 9: timeout waiting for queued request to complete
usb xhci 0: transfer error on slot 1 endpoint 1: Length invalid
usb error xhci 0: TRB 0x4124d000 was not found in the endpoint!
usb error hub 8: error updating port status
usb error control pipe 9: timeout waiting for queued request to complete
usb xhci 0: transfer error on slot 1 endpoint 1: Length invalid
usb error xhci 0: TRB 0x4124d000 was not found in the endpoint!
usb error hub 8: error updating port status
usb error control pipe 9: timeout waiting for queued request to complete
usb xhci 0: transfer error on slot 1 endpoint 1: Length invalid
usb error xhci 0: TRB 0x4124d000 was not found in the endpoint!
usb error hub 8: error updating port status

... repeats forever, even if all USB devices are removed

[kallisti5]

I'm seeing other stall regressions on x86_64 with usb_disk's (usb flash)

KERN: usb hub 31: port 0: new device connected
KERN: usb_disk: device reports a lun count of 1
KERN: usb_disk: vendor_identification    "Mass    "
KERN: usb_disk: product_identification   "Storage Device  "
KERN: usb_disk: product_revision_level   "1.00"
KERN: publish device: node 0xffffffffe1bf4978, path disk/usb/0/0/raw, module drivers/disk/usb_disk/device_v1
KERN: DMAResource@0xffffff8048053788: low/high 0/ffffffffffffffff, max segment count 16, align 1, boundary 0, max transfer 65536, max segment size 18446744073709551615
KERN: usb_disk: got device name "Mass Storage Device 1.00": No error
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_std_ops(0x1)
KERN: intel: pm_identify_partition(109, 10: 0, 64021856256, 512)
KERN: btrfs: [2684259253: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff804883f1c8)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: intel: pm_scan_partition(109, 10: 0, 64021856256, 512)
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_identify_partition(109, 2048, 33554432, 512)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_identify_partition(109, 11: 2048, 33554432, 512)
KERN: btrfs: [2684318518: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff80488110b0)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: intel: ep_std_ops(0x1)
KERN: intel: ep_identify_partition(109, 33556480, 314572800, 512)
KERN: intel: ep_std_ops(0x2)
KERN: intel: pm_identify_partition(109, 12: 33556480, 314572800, 512)
KERN: btrfs: [2684375258: 165711] invalid superblock!
KERN: exfat: invalid superblock!
KERN: ext2: invalid superblock!
KERN: identify(109, 0xffffff80488110b0)
KERN: ntfs: error: identify_partition: boot signature doesn't match
KERN: usb_disk: unhandled ioctl 10102
KERN: bfs: mounted "Haiku" (root node at 131072, device = /dev/disk/usb/0/0/1)
KERN: slab memory manager: created area 0xffffff804f001000 (7417720)
KERN: usb xhci 0: transfer error on slot 9 endpoint 3: Stall
KERN: usb error xhci 0: cancel queued transfers: halted endpoint, reset!
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 1 time
KERN: usb_disk: receiving the command status wrapper failed: Operation timed out
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
KERN: could not write back block 98312 (Operation timed out)
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
Last message repeated 3 times
KERN: could not write back block 98312 (Operation timed out)
KERN: usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out

$ lspci | grep USB
02:00.0 USB controller: Advanced Micro Devices, Inc. [AMD] Device 43d0 (rev 01)
0a:00.0 USB controller: ASMedia Technology Inc. ASM2142/ASM3142 USB 3.1 Host Controller
10:00.3 USB controller: Advanced Micro Devices, Inc. [AMD] Matisse USB 3.0 Host Controller

/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M
    .
    |__ Port 5: Dev 4, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 11, If 0, Class=Mass Storage, Driver=usb-storage, 480M

[waddlesplash]

Did this device work previously? When did it stop working?

[waddlesplash]

KERN: usb_disk: receiving the command status wrapper failed: Operation timed out

After this happens, a "reset recovery" should take place which cancels queued transfers, resets massbulk, etc. I don't see that happening in these logs?

[waddlesplash]

usb error control pipe 9: timeout waiting for queued request to complete
usb xhci 0: transfer error on slot 1 endpoint 1: Length invalid
usb error xhci 0: TRB 0x4124d000 was not found in the endpoint!

A full log with all tracing enabled in the XHCI driver would be helpful here. I have a hunch these errors are occurring upon invocation of the "stop endpoint" command, which merely indicates the TRB had no data transferred to it yet, but I would have to read the spec and other drivers to determine if that is the case.

That pushes the problem up a level, though. It means the hub is just not returning any data to the controller. That sounds like a problem.

[kallisti5]

Replying to waddlesplash:

Did this device work previously? When did it stop working?

Just a simple USB to MicroSD adapter with a MicroSD card inserted. Never had any trouble with it before (but unable to provide bisect hrev ;-) )

[X512]

USB device connected to upper left port recognized as USB 3

[X512]

Some information about embedded hubs in USB 3 host controller chips: ​https://techcommunity.microsoft.com/t5/microsoft-usb-blog/how-to-map-ports-for-add-in-host-controllers/ba-p/270729

XHCI Spec revision 1.2 (​https://www.intel.com/content/dam/www/public/us/en/documents/technical-specifications/extensible-host-controler-interface-usb-xhci.pdf)

4.24.2.2 External Port to USB Connector mapping

[X512]

On Linux there are 2 root hubs for XHCI: for USB 2 and for USB 3. It are populated based on XHCI_SUPPORTED_PROTOCOLS list (​https://github.com/haiku/haiku/blob/17d9a20c621ba91b24b265a0c1becde9492be4c0/src/add-ons/kernel/busses/usb/xhci.cpp#LL638C19-L638C43).

In Linux code: ​https://github.com/starfive-tech/linux/blob/d9eee31aaec51ade1641391836c1f07dd2151a4a/drivers/usb/host/xhci-mem.c#L2347

It see USB version and add port to corresponding root hub.

USB 2 root hub:

Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            9 Hub
  bDeviceSubClass         0 
  bDeviceProtocol         1 Single TT
  bMaxPacketSize0        64
  idVendor           0x1d6b Linux Foundation
  idProduct          0x0002 2.0 root hub
  bcdDevice            5.15
  iManufacturer           3 Linux 5.15.0-starfive xhci-hcd
  iProduct                2 xHCI Host Controller
  iSerial                 1 0000:01:00.0
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0019
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         9 Hub
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 Full speed (or root) hub
      iInterface              0 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0004  1x 4 bytes
        bInterval              12
Hub Descriptor:
  bLength               9
  bDescriptorType      41
  nNbrPorts             1
  wHubCharacteristic 0x0009
    Per-port power switching
    Per-port overcurrent protection
    TT think time 8 FS bits
  bPwrOn2PwrGood       10 * 2 milli seconds
  bHubContrCurrent      0 milli Ampere
  DeviceRemovable    0x02
  PortPwrCtrlMask    0xff
 Hub Port Status:
   Port 1: 0000.0503 highspeed power enable connect
Device Status:     0x0001
  Self Powered

USB 3 root hub:

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               3.00
  bDeviceClass            9 Hub
  bDeviceSubClass         0 
  bDeviceProtocol         3 
  bMaxPacketSize0         9
  idVendor           0x1d6b Linux Foundation
  idProduct          0x0003 3.0 root hub
  bcdDevice            5.15
  iManufacturer           3 Linux 5.15.0-starfive xhci-hcd
  iProduct                2 xHCI Host Controller
  iSerial                 1 0000:01:00.0
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x001f
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         9 Hub
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 Full speed (or root) hub
      iInterface              0 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0004  1x 4 bytes
        bInterval              12
        bMaxBurst               0
Hub Descriptor:
  bLength              12
  bDescriptorType      42
  nNbrPorts             4
  wHubCharacteristic 0x0009
    Per-port power switching
    Per-port overcurrent protection
  bPwrOn2PwrGood       10 * 2 milli seconds
  bHubContrCurrent      0 milli Ampere
  bHubDecLat          0.0 micro seconds
  wHubDelay             0 nano seconds
  DeviceRemovable    0x00
 Hub Port Status:
   Port 1: 0000.02a0 5Gbps power Rx.Detect
   Port 2: 0000.0263 5Gbps power suspend enable connect
   Port 3: 0000.02a0 5Gbps power Rx.Detect
   Port 4: 0000.02a0 5Gbps power Rx.Detect
Binary Object Store Descriptor:
  bLength                 5
  bDescriptorType        15
  wTotalLength       0x000f
  bNumDeviceCaps          1
  SuperSpeed USB Device Capability:
    bLength                10
    bDescriptorType        16
    bDevCapabilityType      3
    bmAttributes         0x02
      Latency Tolerance Messages (LTM) Supported
    wSpeedsSupported   0x0008
      Device can operate at SuperSpeed (5Gbps)
    bFunctionalitySupport   1
      Lowest fully-functional device speed is Full Speed (12Mbps)
    bU1DevExitLat           4 micro seconds
    bU2DevExitLat         231 micro seconds
Device Status:     0x0001
  Self Powered

[X512]

This happens if reading USB 3 disk connected to root hub USB 3 port:

usb xhci 0: transfer error on slot 2 endpoint 5: Babble detected
usb_disk: sending or receiving of the data failed: Device FIFO overrun
usb error control pipe 25: timeout waiting for queued request to complete
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: cancel queued transfers: could not stop endpoint: I/O error!
usb error control pipe 25: timeout waiting for queued request to complete
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: cancel queued transfers: could not stop endpoint: I/O error!
usb error control pipe 25: timeout waiting for queued request to complete
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: cancel queued transfers: could not stop endpoint: I/O error!
file_cache: read pages failed: I/O error
usb_disk: acquire_sem failed while waiting for data transfer: Operation timed out
usb xhci 0: transfer error on slot 2 endpoint 2: TRB
usb_disk: sending the command block wrapper failed: Device stalled
usb error control pipe 25: timeout waiting for queued request to complete
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: unsuccessful command 15, error Context state (19)
usb error xhci 0: cancel queued transfers: could not stop endpoint: I/O error!

[waddlesplash]

"Embedded Hubs" seem to mean ones in the device but on on the XHC. "Integrated Hubs" seem to be ones in the XHC itself but not the root hub, so I guess that is what is happening here.

There is some information in the spec about "Tier Mismatch" occurring and also the "Integrated Hub Implemented" flag. I guess we should check what other OSes do to handle those.

[waddlesplash]

Have you tried:

1. hacking in a mechanism to the XHCI driver to ignore the USB2 ports?

2. enabling full tracing, and seeing what differs under MSI-X?

[Luposian]

Has anyone tried using a Logitech USB dongle that controls both a keyboard and mouse from the same dongle? I mentioned this, but it was theorized that it would not work (as it reports two devices), but has anyone actually tried it? If it's a physical limitation (you simply cannot use two ports (one per device; mouse and keyboard)), then this should solve it. If it's an interpretive (software) limitation, then this probably won't work. But it's worth a shot.

[korli]

Proposed patch on Gerrit: ​https://review.haiku-os.org/c/haiku/+/7341

[X512]

Replying to korli:

Proposed patch on Gerrit: ​https://review.haiku-os.org/c/haiku/+/7341

This patch help a bit, but do not fix root problem.

[waddlesplash]

Merged in hrev57519.

[waddlesplash]

hrev57529 may fix this, please retest.