[EXT] USB3 XHCI crashing with USB 3 hub on Octeon

[Aaron Williams <awilliams@marvell.com>]

I have a follow-up. USB is working on our OcteonTX boards running 2020.10. It 
may be something specific to the Octeon port. Note that I did see a problem 
where the scratchpad memory is using direct pointers instead of physical 
addresses (which will not work on MIPS). As far as I know, however, the Octeon 
XHCI controller does not use the scratchpad memory.

-Aaron

On Friday, February 19, 2021 5:57:47 AM PST Aaron Williams wrote:
> External Email
> 
> ----------------------------------------------------------------------
> Hi all,
> 
> While backporting the latest USB support in U-Boot to support USB 3 hubs I
> decided to try the latest U-Boot for Octeon which should contain everything.
> When I start USB, however, with a USB 3 thumb drive plugged into a USB 3
> hub, I am seeing a crash. I have enabled all of the debugging support for
> usb.c, usb_hub.c, xhci.c, xhci-ring.c and xhci_mem.c
> 
> In my backported code which is a bit hacked up due to the lack of DT
> support, I am seeing it fail when it attempts to set the hub depth. Note
> that everything works fine with a USB 2 hub. I was hoping to compare the
> stock U- Boot with my hacked up code to track down the issue.
> 
> -Aaron
> 
> Here are the logs:
> 
> => usb start
> starting USB...
> Bus xhci at 1680000000000: xhci_register: dev='xhci at 1680000000000',
> ctrl=ffffffff8eea1aa0, hccr=8001680000000000, hcor=8001680000000020
> // Halt the HC: 8001680000000020
> // Reset the HC
> Register 2000140 NbrPorts 2
> Starting the controller
> USB XHCI 1.00
> Bus xhci at 1690000000000: xhci_register: dev='xhci at 1690000000000',
> ctrl=ffffffff8eeab040, hccr=8001690000000000, hcor=8001690000000020
> // Halt the HC: 8001690000000020
> // Reset the HC
> Register 2000140 NbrPorts 2
> Starting the controller
> USB XHCI 1.00
> scanning bus xhci at 1680000000000 for devices... xhci_alloc_device:
> dev='xhci at 1680000000000', udev=ffffffff8ee9c280
> set address 1
> usb_control_msg: request: 0x5, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_REQ_SET_ADDRESS
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x100 index 0x0
> length 0x12
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_DEVICE request
> scrlen = 18
>  req->length = 18
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x9
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_CONFIG config
> scrlen = 25
>  req->length = 9
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x1F
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_CONFIG config
> scrlen = 25
>  req->length = 31
> get_conf_no 0 Result 25, wLength 31
> if 0, ep 0
> ##EP epmaxpacketin[1] = 2048
> set configuration 1
> usb_control_msg: request: 0x9, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> new device strings: Mfr=1, Product=2, SerialNumber=0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x300 index 0x0
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_STRING config
> scrlen = 4
>  req->length = 255
> USB device number 1 default language ID 0x409
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x301 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_STRING config
> scrlen = 14
>  req->length = 255
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x302 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1680000000000', portnr=0
> USB_DT_STRING config
> scrlen = 42
>  req->length = 255
> Manufacturer U-Boot
> Product      XHCI Host Controller
> SerialNumber
> usb_hub_post_probe
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> USB_DT_HUB config
> scrlen = 8
>  req->length = 4
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0xC
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> USB_DT_HUB config
> scrlen = 8
>  req->length = 12
> 2 ports detected
> ganged power switching
> standalone hub
> individual port over-current protection
> TT requires at most 8 FS bit times (666 ns)
> power on to power good time: 20ms
> hub controller current requirement: 0mA
> port 1 is removable
> port 2 is removable
> usb_control_msg: request: 0x0, requesttype: 0xA0, value 0x0 index 0x0 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 2
>  req->length = 4
> get_hub_status returned status 1, change 802
> local power source is lost (inactive)
> no over-current condition exists
> xhci_update_hub_device: dev='xhci at 1680000000000', udev=ffffffff8eeae040
> enabling power on all ports
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> port 1 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x2 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> port 2 returns 0
> pgood_delay=20ms
> devnum=1 poweron: query_delay=100 connect_timeout=1100
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 2 Status 100 Change 0
> devnum=1 port=2: timeout
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1680000000000', udev=ffffffff8eeae040,
> udev->dev='usb_hub', portnr=0
> scrlen = 4
>  req->length = 4
> Port 1 Status 100 Change 0
> devnum=1 port=1: timeout
> 1 USB Device(s) found
> scanning bus xhci at 1690000000000 for devices... xhci_alloc_device:
> dev='xhci at 1690000000000', udev=ffffffff8ee9c280
> set address 1
> usb_control_msg: request: 0x5, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_REQ_SET_ADDRESS
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x100 index 0x0
> length 0x12
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_DEVICE request
> scrlen = 18
>  req->length = 18
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x9
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_CONFIG config
> scrlen = 25
>  req->length = 9
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x1F
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_CONFIG config
> scrlen = 25
>  req->length = 31
> get_conf_no 0 Result 25, wLength 31
> if 0, ep 0
> ##EP epmaxpacketin[1] = 2048
> set configuration 1
> usb_control_msg: request: 0x9, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> new device strings: Mfr=1, Product=2, SerialNumber=0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x300 index 0x0
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_STRING config
> scrlen = 4
>  req->length = 255
> USB device number 1 default language ID 0x409
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x301 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_STRING config
> scrlen = 14
>  req->length = 255
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x302 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9c280,
> udev->dev='xhci at 1690000000000', portnr=0
> USB_DT_STRING config
> scrlen = 42
>  req->length = 255
> Manufacturer U-Boot
> Product      XHCI Host Controller
> SerialNumber
> usb_hub_post_probe
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> USB_DT_HUB config
> scrlen = 8
>  req->length = 4
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0xC
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> USB_DT_HUB config
> scrlen = 8
>  req->length = 12
> 2 ports detected
> ganged power switching
> standalone hub
> individual port over-current protection
> TT requires at most 8 FS bit times (666 ns)
> power on to power good time: 20ms
> hub controller current requirement: 0mA
> port 1 is removable
> port 2 is removable
> usb_control_msg: request: 0x0, requesttype: 0xA0, value 0x0 index 0x0 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 2
>  req->length = 4
> get_hub_status returned status 1, change 802
> local power source is lost (inactive)
> no over-current condition exists
> xhci_update_hub_device: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0
> enabling power on all ports
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> port 1 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x2 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> port 2 returns 0
> pgood_delay=20ms
> devnum=1 poweron: query_delay=100 connect_timeout=1100
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = FULLSPEED
> scrlen = 4
>  req->length = 4
> Port 1 Status 101 Change 1
> devnum=1 port=1: USB dev found
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = FULLSPEED
> scrlen = 4
>  req->length = 4
> portstatus 101, change 1, 12 Mb/s
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x10 index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> clear port connect change, actual port 1 status  = 0x6e1
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_hub_port_reset: resetting 'usb_hub' port 1...
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x4 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = FULLSPEED
> scrlen = 4
>  req->length = 4
> portstatus 111, change 0, 12 Mb/s
> STAT_C_CONNECTION = 0 STAT_CONNECTION = 1  USB_PORT_STAT_ENABLE 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x4 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = HIGHSPEED
> scrlen = 4
>  req->length = 4
> portstatus 503, change 10, 480 Mb/s
> STAT_C_CONNECTION = 0 STAT_CONNECTION = 1  USB_PORT_STAT_ENABLE 1
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x14 index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> clear port reset change, actual port 1 status  = 0xe03
> scrlen = 0
>  req->length = 0
> Len is 0
> xhci_alloc_device: dev='xhci at 1690000000000', udev=ffffffff8ee9b420
> EP STATE RUNNING.
> set address 2
> usb_control_msg: request: 0x5, requesttype: 0x0, value 0x2 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> Setting up addressable devices ffffffff8eeab980
> route string 0
> port_num = 1
> SPEED = 3
> Setting Packet size = 64bytes
> EP STATE RUNNING.
> Successful Address Device command
> xHC internal address is: 1
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x100 index 0x0
> length 0x12
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=128 (0x80), value=256 (0x100), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacb80, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 256,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 18
> length_field = 18, length = 18,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x9
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=128 (0x80), value=512 (0x200), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacbb0, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 512,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 9
> length_field = 9, length = 9,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x19
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=128 (0x80), value=512 (0x200), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacbe0, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 512,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 25
> length_field = 25, length = 25,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> get_conf_no 0 Result 25, wLength 25
> if 0, ep 0
> ##EP epmaxpacketin[1] = 1
> set configuration 1
> usb_control_msg: request: 0x9, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> EP STATE RUNNING.
> Successful Configure Endpoint command
> req=9 (0x9), type=0 (0x0), value=1 (0x1), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacc10, start_cycle 1
> req->requesttype = 0, req->request = 9,le16_to_cpu(req->value) =
> 1,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> new device strings: Mfr=0, Product=1, SerialNumber=0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x300 index 0x0
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=128 (0x80), value=768 (0x300), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacc30, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 768,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 255
> length_field = 255, length = 255,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> USB device number 2 default language ID 0x409
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x301 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=128 (0x80), value=769 (0x301), index=1033
> EP STATE RUNNING.
> start_trb ffffffff8eeacc60, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 769,le16_to_cpu(req->index) = 1033,le16_to_cpu(req->length) = 255
> length_field = 255, length = 255,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Manufacturer
> Product      USB2.0 Hub
> SerialNumber
> usb_hub_post_probe
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2900 index 0x0
> length 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=160 (0xa0), value=10496 (0x2900), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeacc90, start_cycle 1
> req->requesttype = 160, req->request = 6,le16_to_cpu(req->value) =
> 10496,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2900 index 0x0
> length 0x9
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=6 (0x6), type=160 (0xa0), value=10496 (0x2900), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeaccc0, start_cycle 1
> req->requesttype = 160, req->request = 6,le16_to_cpu(req->value) =
> 10496,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 9
> length_field = 9, length = 9,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> 4 ports detected
> individual port power switching
> standalone hub
> individual port over-current protection
> Single TT
> TT requires at most 32 FS bit times (2664 ns)
> power on to power good time: 100ms
> hub controller current requirement: 100mA
> port 1 is removable
> port 2 is removable
> port 3 is removable
> port 4 is removable
> usb_control_msg: request: 0x0, requesttype: 0xA0, value 0x0 index 0x0 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=0 (0x0), type=160 (0xa0), value=0 (0x0), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeaccf0, start_cycle 1
> req->requesttype = 160, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> get_hub_status returned status 0, change 0
> local power source is good
> no over-current condition exists
> xhci_update_hub_device: dev='xhci at 1690000000000', udev=ffffffff8eeb0920
> EP STATE RUNNING.
> Successful Configure Endpoint command
> enabling power on all ports
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeacd20, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 1 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x2 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=2
> EP STATE RUNNING.
> start_trb ffffffff8eeacd40, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 2,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 2 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x3 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=3
> EP STATE RUNNING.
> start_trb ffffffff8eeacd60, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 3,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 3 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x4 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=4
> EP STATE RUNNING.
> start_trb ffffffff8eeacd80, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 4,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 4 returns 0
> pgood_delay=100ms
> devnum=2 poweron: query_delay=100 connect_timeout=1100
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = SUPERSPEED
> scrlen = 4
>  req->length = 4
> Port 2 Status 703 Change 1
> devnum=1 port=2: USB dev found
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = SUPERSPEED
> scrlen = 4
>  req->length = 4
> portstatus 703, change 1, 5 Gb/s
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x10 index 0x2
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> clear port connect change, actual port 2 status  = 0x1203
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_hub_port_reset: resetting 'usb_hub' port 2...
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x4 index 0x2 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> scrlen = 0
>  req->length = 0
> Len is 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> SPEED = SUPERSPEED
> scrlen = 4
>  req->length = 4
> portstatus 703, change 10, 5 Gb/s
> STAT_C_CONNECTION = 0 STAT_CONNECTION = 1  USB_PORT_STAT_ENABLE 1
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x14 index 0x2
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeae9e0,
> udev->dev='usb_hub', portnr=0
> clear port reset change, actual port 2 status  = 0x1203
> scrlen = 0
>  req->length = 0
> Len is 0
> xhci_alloc_device: dev='xhci at 1690000000000', udev=ffffffff8ee9b420
> EP STATE RUNNING.
> set address 3
> usb_control_msg: request: 0x5, requesttype: 0x0, value 0x3 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> Setting up addressable devices ffffffff8eeab980
> route string 0
> port_num = 2
> SPEED = 5
> Setting Packet size = 512bytes
> EP STATE RUNNING.
> Successful Address Device command
> xHC internal address is: 2
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x100 index 0x0
> length 0x12
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=256 (0x100), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb2580, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 256,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 18
> length_field = 18, length = 18,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x9
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=512 (0x200), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb25b0, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 512,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 9
> length_field = 9, length = 9,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x200 index 0x0
> length 0x1F
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=512 (0x200), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb25e0, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 512,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 31
> length_field = 31, length = 31,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> get_conf_no 0 Result 31, wLength 31
> if 0, ep 0
> ##EP epmaxpacketin[1] = 2
> set configuration 1
> usb_control_msg: request: 0x9, requesttype: 0x0, value 0x1 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> EP STATE RUNNING.
> Successful Configure Endpoint command
> req=9 (0x9), type=0 (0x0), value=1 (0x1), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb2610, start_cycle 1
> req->requesttype = 0, req->request = 9,le16_to_cpu(req->value) =
> 1,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> new device strings: Mfr=1, Product=2, SerialNumber=0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x300 index 0x0
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=768 (0x300), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb2630, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 768,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 255
> length_field = 255, length = 255,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> USB device number 3 default language ID 0x409
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x301 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=769 (0x301), index=1033
> EP STATE RUNNING.
> start_trb ffffffff8eeb2660, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 769,le16_to_cpu(req->index) = 1033,le16_to_cpu(req->length) = 255
> length_field = 255, length = 255,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0x80, value 0x302 index 0x409
> length 0xFF
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=128 (0x80), value=770 (0x302), index=1033
> EP STATE RUNNING.
> start_trb ffffffff8eeb2690, start_cycle 1
> req->requesttype = 128, req->request = 6,le16_to_cpu(req->value) =
> 770,le16_to_cpu(req->index) = 1033,le16_to_cpu(req->length) = 255
> length_field = 255, length = 255,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Manufacturer VIA Labs, Inc.
> Product      4-Port USB 3.0 Hub
> SerialNumber
> usb_hub_post_probe
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=160 (0xa0), value=10752 (0x2a00), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb26c0, start_cycle 1
> req->requesttype = 160, req->request = 6,le16_to_cpu(req->value) =
> 10752,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x6, requesttype: 0xA0, value 0x2A00 index 0x0
> length 0xC
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=6 (0x6), type=160 (0xa0), value=10752 (0x2a00), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb26f0, start_cycle 1
> req->requesttype = 160, req->request = 6,le16_to_cpu(req->value) =
> 10752,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 12
> length_field = 12, length = 12,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> 4 ports detected
> individual port power switching
> standalone hub
> individual port over-current protection
> TT requires at most 8 FS bit times (666 ns)
> power on to power good time: 2ms
> hub controller current requirement: 2mA
> port 1 is removable
> port 2 is removable
> port 3 is removable
> port 4 is removable
> usb_control_msg: request: 0x0, requesttype: 0xA0, value 0x0 index 0x0 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=0 (0x0), type=160 (0xa0), value=0 (0x0), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb2720, start_cycle 1
> req->requesttype = 160, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> get_hub_status returned status 0, change 0
> local power source is good
> no over-current condition exists
> xhci_update_hub_device: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40
> EP STATE RUNNING.
> Successful Configure Endpoint command
> set hub (ffffffff8eeb2f40) depth to 0
> usb_control_msg: request: 0xC, requesttype: 0x20, value 0x0 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=12 (0xc), type=32 (0x20), value=0 (0x0), index=0
> EP STATE RUNNING.
> start_trb ffffffff8eeb2750, start_cycle 1
> req->requesttype = 32, req->request = 12,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 0,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> enabling power on all ports
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2770, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 1 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x2 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=2
> EP STATE RUNNING.
> start_trb ffffffff8eeb2790, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 2,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 2 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x3 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=3
> EP STATE RUNNING.
> start_trb ffffffff8eeb27b0, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 3,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 3 returns 0
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x8 index 0x4 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=3 (0x3), type=35 (0x23), value=8 (0x8), index=4
> EP STATE RUNNING.
> start_trb ffffffff8eeb27d0, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 8,le16_to_cpu(req->index) = 4,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 4 returns 0
> pgood_delay=2ms
> devnum=3 poweron: query_delay=100 connect_timeout=1100
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeacda0, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Port 1 Status 100 Change 0
> devnum=2 port=1: timeout
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x2 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=2
> EP STATE RUNNING.
> start_trb ffffffff8eeacdd0, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 2,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Port 2 Status 100 Change 0
> devnum=2 port=2: timeout
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x3 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=3
> EP STATE RUNNING.
> start_trb ffffffff8eeace00, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 3,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Port 3 Status 100 Change 0
> devnum=2 port=3: timeout
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x4 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb0920,
> udev->dev='usb_hub', portnr=1
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=4
> EP STATE RUNNING.
> start_trb ffffffff8eeace30, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 4,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Port 4 Status 100 Change 0
> devnum=2 port=4: timeout
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb27f0, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> Port 1 Status 207 Change 31
> port 1 reset change
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x14 index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=20 (0x14), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2820, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 20,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 1 BH reset change
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x1D index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=29 (0x1d), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2840, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 29,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> devnum=3 port=1: USB dev found
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2860, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> portstatus 207, change 1, 1.5 Mb/s
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x10 index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=16 (0x10), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2890, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 16,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_hub_port_reset: resetting 'usb_hub' port 1...
> usb_control_msg: request: 0x3, requesttype: 0x23, value 0x4 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=3 (0x3), type=35 (0x23), value=4 (0x4), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb28b0, start_cycle 1
> req->requesttype = 35, req->request = 3,le16_to_cpu(req->value) =
> 4,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> usb_control_msg: request: 0x0, requesttype: 0xA3, value 0x0 index 0x1 length
> 0x4
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=0 (0x0), type=163 (0xa3), value=0 (0x0), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb28d0, start_cycle 1
> req->requesttype = 163, req->request = 0,le16_to_cpu(req->value) =
> 0,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 4
> length_field = 4, length = 4,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> portstatus 207, change 10, 1.5 Mb/s
> STAT_C_CONNECTION = 0 STAT_CONNECTION = 1  USB_PORT_STAT_ENABLE 1
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x14 index 0x1
> length 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=20 (0x14), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2900, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 20,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> xhci_alloc_device: dev='xhci at 1690000000000', udev=ffffffff8ee9b420
> EP STATE RUNNING.
> set address 4
> usb_control_msg: request: 0x5, requesttype: 0x0, value 0x4 index 0x0 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8ee9b420,
> udev->dev='usb_hub', portnr=1
> Setting up addressable devices ffffffff8eeab980
> route string 1
> port_num = 2
> SPEED = 1
> Setting Packet size = 8bytes
> EP STATE RUNNING.
> Device not responding to set address.
> 
>       USB device not accepting new address (error=80000000)
> hub: disabling port 1
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x1 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=1 (0x1), index=1
> EP STATE RUNNING.
> start_trb ffffffff8eeb2920, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 1,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> port 1 suspend change
> usb_control_msg: request: 0x1, requesttype: 0x23, value 0x2 index 0x1 length
> 0x0
> xhci_submit_control_msg: dev='xhci at 1690000000000', udev=ffffffff8eeb2f40,
> udev->dev='usb_hub', portnr=2
> req=1 (0x1), type=35 (0x23), value=2 (0x2), index=1
> WARN halted endpoint, queueing URB anyway.
> EP STATE RUNNING.
> start_trb ffffffff8eeb2940, start_cycle 1
> req->requesttype = 35, req->request = 1,le16_to_cpu(req->value) =
> 2,le16_to_cpu(req->index) = 1,le16_to_cpu(req->length) = 0
> length_field = 0, length = 0,xhci_td_remainder(length) = 0 ,
> TRB_INTR_TARGET(0) = 0
> XHCI control transfer timed out, aborting...
> EP STATE RUNNING.
> Unexpected XHCI event TRB, skipping... (0eea9c20 00000000 13000000 02008401)
> BUG at drivers/usb/host/xhci-ring.c:503/abort_td()!
> BUG!
> resetting ...