USB3 XHCI crashing with USB 3 hub on Octeon

* USB3 XHCI crashing with USB 3 hub on Octeon
@ 2021-02-19 13:57 Aaron Williams
  2021-02-23  7:31 ` [EXT] " Aaron Williams
  0 siblings, 1 reply; 13+ messages in thread
From: Aaron Williams @ 2021-02-19 13:57 UTC (permalink / raw)
  To: u-boot

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 ...

^ permalink raw reply	[flat|nested] 13+ messages in thread