Re: kern/51126: USB device problem after nick-nhusb merge

[mlh%goathill.org@localhost (MLH)]

Nick Hudson wrote:
> The following reply was made to PR kern/51126; it has been noted by GNATS.
> 
> From: Nick Hudson <skrll%netbsd.org@localhost>
> To: gnats-bugs%NetBSD.org@localhost, kern-bug-people%netbsd.org@localhost,
>  gnats-admin%netbsd.org@localhost, netbsd-bugs%netbsd.org@localhost
> Cc: 
> Subject: Re: kern/51126: USB device problem after nick-nhusb merge
> Date: Mon, 9 May 2016 09:57:33 +0100
> 
>  ----------------------
>  >
>  > Garmin connect (has two memory devices) :
>  >
>  > 1461677509.880428 uhub_intr#7@0: called!
>  > 1461677509.880429 uhub_intr#7@0: uhub4
...
>  
>  Can you turn on EHCI_DEBUG/ehcidebug=10 and send the output from the 
>  Garmin connect, please?

with: NetBSD 7.99.29 (USBDEBUG) #0: Mon May  9 08:55:23 EDT 2016

The output from just plugging in a Garmin E500 (only one memory
device) is 400k long. Suggestions?

Starts with:

1462803139.472560 ehci_intr#1@0: called!
1462803139.472561 ehci_intr1#1@0: called!
1462803139.472562 ehci_intr1#1@0: sc=0xfffffe81075c7008 intrs=0x9(0xc009) eintrs=0x1
1462803139.472563 ehci_intr1#1@0: INT=1  ERRINT=0
1462803139.472565 ehci_softintr#1@0: called!
1462803139.472565 ehci_check_qh_intr#1@0: called!
1462803139.472566 ehci_check_qh_intr#1@0: active ex=0xfffffe81076c3960
1462803139.472566 ehci_check_qh_intr#1@0: ex=0xfffffe81076c3960 std=0xffff800049d61e80 still active
1462803139.472566 ehci_check_qh_intr#1@0: --- still active start ---
1462803139.472567 ehci_dump_sqtds#1@0: called!
1462803139.472567 ehci_dump_sqtd#1@0: called!
1462803139.472567 ehci_dump_sqtd#1@0: QTD(0xffff800049d61e80) at 0x41397e80:
1462803139.472567 ehci_dump_qtd#1@0: called!
1462803139.472567 ehci_dump_qtd#1@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00018d80
1462803139.472568 ehci_dump_qtd#1@0:    toggle = 0 ioc = 1 bytes = 0x1 c_page = 0
1462803139.472568 ehci_dump_qtd#1@0:      cerr = 3 pid = 1 stat  = 80
1462803139.472568 ehci_dump_qtd#1@0: active =1 halted=0 buferr=0 babble=0
1462803139.472568 ehci_dump_qtd#1@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472568 ehci_dump_qtd#1@0: buffer[0] = 0x4137fc80  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472568 ehci_dump_qtd#1@0: buffer[4] = 0
1462803139.472568 ehci_check_qh_intr#1@0: --- still active end ---
1462803139.472569 ehci_check_qh_intr#2@0: called!
1462803139.472569 ehci_check_qh_intr#2@0: ex=0xfffffe81076c3af0 done
1462803139.472569 ehci_idone#1@0: called!
1462803139.472569 ehci_idone#1@0: ex=0xfffffe81076c3af0
1462803139.472570 ehci_idone#1@0: xfer=0xfffffe81076c3af0, pipe=0xfffffe810773ef08 ready
1462803139.472570 ehci_idone#1@0: --- dump start ---
1462803139.472570 ehci_dump_sqtds#2@0: called!
1462803139.472570 ehci_dump_sqtd#2@0: called!
1462803139.472570 ehci_dump_sqtd#2@0: QTD(0xffff800049d61f00) at 0x41397f00:
1462803139.472570 ehci_dump_qtd#2@0: called!
1462803139.472570 ehci_dump_qtd#2@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00008d00
1462803139.472570 ehci_dump_qtd#2@0:    toggle = 0 ioc = 1 bytes = 0 c_page = 0
1462803139.472570 ehci_dump_qtd#2@0:      cerr = 3 pid = 1 stat  = 0
1462803139.472570 ehci_dump_qtd#2@0: active =0 halted=0 buferr=0 babble=0
1462803139.472571 ehci_dump_qtd#2@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472571 ehci_dump_qtd#2@0: buffer[0] = 0x4137fd81  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472571 ehci_dump_qtd#2@0: buffer[4] = 0
1462803139.472571 ehci_idone#1@0: --- dump end ---
1462803139.472571 ehci_idone#1@0: len=1 actlen=1 status=0x00008d00
1462803139.472571 ehci_idone#1@0: ex=0xfffffe81076c3af0 done
1462803139.472572 ehci_device_intr_done#1@0: called!
1462803139.472573 ehci_device_intr_done#1@0: xfer=0xfffffe81076c3af0, actlen=1
1462803139.472576 ehci_device_intr_start#1@0: called!
1462803139.472576 ehci_device_intr_start#1@0: xfer=0xfffffe81076c3af0 len=1 flags=132
1462803139.472576 ehci_reset_sqtd_chain#1@0: called!
1462803139.472577 ehci_reset_sqtd_chain#1@0: xfer=0xfffffe81076c3af0 len 1 isread 1 toggle 0
1462803139.472577 ehci_reset_sqtd_chain#1@0:     VA 0xffff800049d4cd80
1462803139.472577 ehci_reset_sqtd_chain#1@0: sqtd[1]=0xffff800049d61f00 prev 0x0
1462803139.472578 ehci_reset_sqtd_chain#1@0:     len=1 curlen=1 curoffs=0
1462803139.472578 ehci_reset_sqtd_chain#1@0:       buffer[0/1] 0x00000000 0x4137f000
1462803139.472578 ehci_reset_sqtd_chain#1@0:     va 0xffff800049d4cd80 pa 0x4137fd80 len 1
1462803139.472578 ehci_device_intr_start#1@0: --- dump start ---
1462803139.472579 ehci_dump_sqh#1@0: called!
1462803139.472579 ehci_dump_sqh#1@0: QH(0xffff800049d5ff00) at 0x41395f00:
1462803139.472579 ehci_dump_sqh#1@0:     link 0x41337882 (T = 0):
1462803139.472580 ehci_dump_sqh#1@0:         ITD  = 0  QH   = 1  SITD = 0  FSTN = 0
1462803139.472580 ehci_dump_sqh#1@0:     endp = 0x16102
1462803139.472580 ehci_dump_sqh#1@0:         addr = 0x02  inact = 0  endpt = 1  eps = 2
1462803139.472580 ehci_dump_sqh#1@0:         dtc  = 1     hrecl = 0
1462803139.472580 ehci_dump_sqh#1@0:         ctl  = 0     nrl   = 0  mpl   = 0x1(1)
1462803139.472580 ehci_dump_sqh#1@0:  endphub = 0x40000002
1462803139.472581 ehci_dump_sqh#1@0:       smask = 0x02  cmask = 0x00
1462803139.472581 ehci_dump_sqh#1@0:       huba  = 0x00  port  = 0  mult = 1
1462803139.472581 ehci_dump_sqh#1@0:     link 0x41397f00 (T = 0):
1462803139.472581 ehci_dump_sqh#1@0: Overlay qTD:
1462803139.472581 ehci_dump_qtd#3@0: called!
1462803139.472581 ehci_dump_qtd#3@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00008d00
1462803139.472581 ehci_dump_qtd#3@0:    toggle = 0 ioc = 1 bytes = 0 c_page = 0
1462803139.472581 ehci_dump_qtd#3@0:      cerr = 3 pid = 1 stat  = 0
1462803139.472581 ehci_dump_qtd#3@0: active =0 halted=0 buferr=0 babble=0
1462803139.472582 ehci_dump_qtd#3@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472582 ehci_dump_qtd#3@0: buffer[0] = 0x4137fd81  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472582 ehci_dump_qtd#3@0: buffer[4] = 0
1462803139.472582 ehci_dump_sqtds#3@0: called!
1462803139.472582 ehci_dump_sqtd#3@0: called!
1462803139.472582 ehci_dump_sqtd#3@0: QTD(0xffff800049d61f00) at 0x41397f00:
1462803139.472582 ehci_dump_qtd#4@0: called!
1462803139.472582 ehci_dump_qtd#4@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00018d80
1462803139.472582 ehci_dump_qtd#4@0:    toggle = 0 ioc = 1 bytes = 0x1 c_page = 0
1462803139.472583 ehci_dump_qtd#4@0:      cerr = 3 pid = 1 stat  = 80
1462803139.472583 ehci_dump_qtd#4@0: active =1 halted=0 buferr=0 babble=0
1462803139.472583 ehci_dump_qtd#4@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472583 ehci_dump_qtd#4@0: buffer[0] = 0x4137fd80  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472583 ehci_dump_qtd#4@0: buffer[4] = 0
1462803139.472583 ehci_device_intr_start#1@0: --- dump end ---
1462803139.472589 ehci_roothub_ctrl#1@2: called!
1462803139.472589 ehci_roothub_ctrl#1@2: type=0xa0 request=00
1462803139.472589 ehci_roothub_ctrl#1@2: returning 4
1462803139.472593 ehci_roothub_ctrl#2@2: called!
1462803139.472593 ehci_roothub_ctrl#2@2: type=0xa3 request=00
1462803139.472593 ehci_roothub_ctrl#2@2: get port status i=1
1462803139.472594 ehci_roothub_ctrl#2@2: port status=0x1005
1462803139.472594 ehci_roothub_ctrl#2@2: returning 4
1462803139.472596 ehci_alloc_sqtd#1@2: called!
1462803139.472596 ehci_alloc_sqtd#2@2: called!
1462803139.472597 ehci_alloc_sqtd_chain#1@2: called!
1462803139.472597 ehci_alloc_sqtd_chain#1@2: xfer 0xfffffe81076c37d0 len 4 nsqtd 1 flags 0
1462803139.472597 ehci_alloc_sqtd#3@2: called!
1462803139.472598 ehci_alloc_sqtd_chain#1@2: return sqtd=0xffff800049d61d80
1462803139.472598 ehci_device_ctrl_start#1@2: called!
1462803139.472598 ehci_device_ctrl_start#1@2: type=0xa3, request=0x00, wValue=0x0000, wIndex=0x0002
1462803139.472598 ehci_device_ctrl_start#1@2: len=4, addr=2, endpt=0
1462803139.472599 ehci_device_ctrl_start#1@2: setup 0xffff800049d61f80 status 0xffff800049d61e00 data 0xffff800049d61d80
1462803139.472599 ehci_reset_sqtd_chain#2@2: called!
1462803139.472599 ehci_reset_sqtd_chain#2@2: xfer=0xfffffe81076c37d0 len 4 isread 128 toggle 1
1462803139.472599 ehci_reset_sqtd_chain#2@2:     VA 0xffff800049d4cb80
1462803139.472599 ehci_reset_sqtd_chain#2@2: sqtd[1]=0xffff800049d61d80 prev 0x0
1462803139.472599 ehci_reset_sqtd_chain#2@2:     len=4 curlen=4 curoffs=0
1462803139.472599 ehci_reset_sqtd_chain#2@2:       buffer[0/1] 0x00000000 0x4137f000
1462803139.472600 ehci_reset_sqtd_chain#2@2:     va 0xffff800049d4cb80 pa 0x4137fb80 len 4
1462803139.472600 ehci_device_ctrl_start#1@2: --- dump start ---
1462803139.472600 ehci_dump_sqh#2@2: called!
1462803139.472600 ehci_dump_sqh#2@2: QH(0xffff800049d5ff80) at 0x41395f80:
1462803139.472600 ehci_dump_sqh#2@2:     link 0x41341002 (T = 0):
1462803139.472600 ehci_dump_sqh#2@2:         ITD  = 0  QH   = 1  SITD = 0  FSTN = 0
1462803139.472600 ehci_dump_sqh#2@2:     endp = 0x40406002
1462803139.472601 ehci_dump_sqh#2@2:         addr = 0x02  inact = 0  endpt = 0  eps = 2
1462803139.472601 ehci_dump_sqh#2@2:         dtc  = 1     hrecl = 0
1462803139.472601 ehci_dump_sqh#2@2:         ctl  = 0     nrl   = 4  mpl   = 0x40(64)
1462803139.472601 ehci_dump_sqh#2@2:  endphub = 0x40000000
1462803139.472601 ehci_dump_sqh#2@2:       smask = 0x00  cmask = 0x00
1462803139.472601 ehci_dump_sqh#2@2:       huba  = 0x00  port  = 0  mult = 1
1462803139.472601 ehci_dump_sqh#2@2:     link 0x41397e00 (T = 0):
1462803139.472601 ehci_dump_sqh#2@2: Overlay qTD:
1462803139.472601 ehci_dump_qtd#5@2: called!
1462803139.472601 ehci_dump_qtd#5@2:      next = 0x00000001  altnext = 0x00000009  status = 0x00008c00
1462803139.472601 ehci_dump_qtd#5@2:    toggle = 0 ioc = 1 bytes = 0 c_page = 0
1462803139.472601 ehci_dump_qtd#5@2:      cerr = 3 pid = 0 stat  = 0
1462803139.472601 ehci_dump_qtd#5@2: active =0 halted=0 buferr=0 babble=0
1462803139.472601 ehci_dump_qtd#5@2: xacterr=0 missed=0 split =0 ping  =0
1462803139.472602 ehci_dump_qtd#5@2: buffer[0] = 0  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472602 ehci_dump_qtd#5@2: buffer[4] = 0
1462803139.472602 ehci_dump_sqtds#4@2: called!
1462803139.472602 ehci_dump_sqtd#4@2: called!
1462803139.472602 ehci_dump_sqtd#4@2: QTD(0xffff800049d61f80) at 0x41397f80:
1462803139.472602 ehci_dump_qtd#6@2: called!
1462803139.472602 ehci_dump_qtd#6@2:      next = 0x41397d80  altnext = 0x41397d80  status = 0x00080e80
1462803139.472603 ehci_dump_qtd#6@2:    toggle = 0 ioc = 0 bytes = 0x8 c_page = 0
1462803139.472603 ehci_dump_qtd#6@2:      cerr = 3 pid = 2 stat  = 80
1462803139.472603 ehci_dump_qtd#6@2: active =1 halted=0 buferr=0 babble=0
1462803139.472603 ehci_dump_qtd#6@2: xacterr=0 missed=0 split =0 ping  =0
1462803139.472603 ehci_dump_qtd#6@2: buffer[0] = 0x4137fdc0  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472603 ehci_dump_qtd#6@2: buffer[4] = 0
1462803139.472603 ehci_dump_sqtd#5@2: called!
1462803139.472603 ehci_dump_sqtd#5@2: QTD(0xffff800049d61d80) at 0x41397d80:
1462803139.472603 ehci_dump_qtd#7@2: called!
1462803139.472603 ehci_dump_qtd#7@2:      next = 0x41397e00  altnext = 0x41397e00  status = 0x80040d80
1462803139.472603 ehci_dump_qtd#7@2:    toggle = 1 ioc = 0 bytes = 0x4 c_page = 0
1462803139.472603 ehci_dump_qtd#7@2:      cerr = 3 pid = 1 stat  = 80
1462803139.472604 ehci_dump_qtd#7@2: active =1 halted=0 buferr=0 babble=0
1462803139.472604 ehci_dump_qtd#7@2: xacterr=0 missed=0 split =0 ping  =0
1462803139.472604 ehci_dump_qtd#7@2: buffer[0] = 0x4137fb80  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472604 ehci_dump_qtd#7@2: buffer[4] = 0
1462803139.472604 ehci_dump_sqtd#6@2: called!
1462803139.472604 ehci_dump_sqtd#6@2: QTD(0xffff800049d61e00) at 0x41397e00:
1462803139.472604 ehci_dump_qtd#8@2: called!
1462803139.472604 ehci_dump_qtd#8@2:      next = 0x00000001  altnext = 0x00000001  status = 0x80008c80
1462803139.472604 ehci_dump_qtd#8@2:    toggle = 1 ioc = 1 bytes = 0 c_page = 0
1462803139.472604 ehci_dump_qtd#8@2:      cerr = 3 pid = 0 stat  = 80
1462803139.472604 ehci_dump_qtd#8@2: active =1 halted=0 buferr=0 babble=0
1462803139.472604 ehci_dump_qtd#8@2: xacterr=0 missed=0 split =0 ping  =0
1462803139.472605 ehci_dump_qtd#8@2: buffer[0] = 0  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472605 ehci_dump_qtd#8@2: buffer[4] = 0
1462803139.472605 ehci_device_ctrl_start#1@2: --- dump end ---
1462803139.472810 ehci_intr#2@0: called!
1462803139.472810 ehci_intr1#2@0: called!
1462803139.472811 ehci_intr1#2@0: sc=0xfffffe81075c7008 intrs=0x1(0xc001) eintrs=0x1
1462803139.472812 ehci_intr1#2@0: INT=1  ERRINT=0
1462803139.472813 ehci_softintr#2@0: called!
1462803139.472813 ehci_check_qh_intr#3@0: called!
1462803139.472813 ehci_check_qh_intr#3@0: active ex=0xfffffe81076c3960
1462803139.472813 ehci_check_qh_intr#3@0: ex=0xfffffe81076c3960 std=0xffff800049d61e80 still active
1462803139.472813 ehci_check_qh_intr#3@0: --- still active start ---
1462803139.472814 ehci_dump_sqtds#5@0: called!
1462803139.472814 ehci_dump_sqtd#7@0: called!
1462803139.472814 ehci_dump_sqtd#7@0: QTD(0xffff800049d61e80) at 0x41397e80:
1462803139.472814 ehci_dump_qtd#9@0: called!
1462803139.472814 ehci_dump_qtd#9@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00018d80
1462803139.472814 ehci_dump_qtd#9@0:    toggle = 0 ioc = 1 bytes = 0x1 c_page = 0
1462803139.472814 ehci_dump_qtd#9@0:      cerr = 3 pid = 1 stat  = 80
1462803139.472814 ehci_dump_qtd#9@0: active =1 halted=0 buferr=0 babble=0
1462803139.472814 ehci_dump_qtd#9@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472814 ehci_dump_qtd#9@0: buffer[0] = 0x4137fc80  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472814 ehci_dump_qtd#9@0: buffer[4] = 0
1462803139.472814 ehci_check_qh_intr#3@0: --- still active end ---
1462803139.472815 ehci_check_qh_intr#4@0: called!
1462803139.472815 ehci_check_qh_intr#4@0: active ex=0xfffffe81076c3af0
1462803139.472815 ehci_check_qh_intr#4@0: ex=0xfffffe81076c3af0 std=0xffff800049d61f00 still active
1462803139.472815 ehci_check_qh_intr#4@0: --- still active start ---
1462803139.472815 ehci_dump_sqtds#6@0: called!
1462803139.472815 ehci_dump_sqtd#8@0: called!
1462803139.472815 ehci_dump_sqtd#8@0: QTD(0xffff800049d61f00) at 0x41397f00:
1462803139.472815 ehci_dump_qtd#10@0: called!
1462803139.472815 ehci_dump_qtd#10@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00018d80
1462803139.472815 ehci_dump_qtd#10@0:    toggle = 0 ioc = 1 bytes = 0x1 c_page = 0
1462803139.472815 ehci_dump_qtd#10@0:      cerr = 3 pid = 1 stat  = 80
1462803139.472816 ehci_dump_qtd#10@0: active =1 halted=0 buferr=0 babble=0
1462803139.472816 ehci_dump_qtd#10@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472816 ehci_dump_qtd#10@0: buffer[0] = 0x4137fd80  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472816 ehci_dump_qtd#10@0: buffer[4] = 0
1462803139.472816 ehci_check_qh_intr#4@0: --- still active end ---
1462803139.472816 ehci_check_qh_intr#5@0: called!
1462803139.472816 ehci_check_qh_intr#5@0: ex=0xfffffe81076c37d0 done
1462803139.472817 ehci_idone#2@0: called!
1462803139.472817 ehci_idone#2@0: ex=0xfffffe81076c37d0
1462803139.472817 ehci_idone#2@0: xfer=0xfffffe81076c37d0, pipe=0xfffffe811f591108 ready
1462803139.472817 ehci_idone#2@0: --- dump start ---
1462803139.472817 ehci_dump_sqtds#7@0: called!
1462803139.472817 ehci_dump_sqtd#9@0: called!
1462803139.472817 ehci_dump_sqtd#9@0: QTD(0xffff800049d61f80) at 0x41397f80:
1462803139.472817 ehci_dump_qtd#11@0: called!
1462803139.472817 ehci_dump_qtd#11@0:      next = 0x41397d80  altnext = 0x41397d80  status = 0x80000e00
1462803139.472817 ehci_dump_qtd#11@0:    toggle = 1 ioc = 0 bytes = 0 c_page = 0
1462803139.472817 ehci_dump_qtd#11@0:      cerr = 3 pid = 2 stat  = 0
1462803139.472818 ehci_dump_qtd#11@0: active =0 halted=0 buferr=0 babble=0
1462803139.472818 ehci_dump_qtd#11@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472818 ehci_dump_qtd#11@0: buffer[0] = 0x4137fdc8  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472818 ehci_dump_qtd#11@0: buffer[4] = 0
1462803139.472818 ehci_dump_sqtd#10@0: called!
1462803139.472818 ehci_dump_sqtd#10@0: QTD(0xffff800049d61d80) at 0x41397d80:
1462803139.472819 ehci_dump_qtd#12@0: called!
1462803139.472819 ehci_dump_qtd#12@0:      next = 0x41397e00  altnext = 0x41397e00  status = 0x00000d00
1462803139.472819 ehci_dump_qtd#12@0:    toggle = 0 ioc = 0 bytes = 0 c_page = 0
1462803139.472819 ehci_dump_qtd#12@0:      cerr = 3 pid = 1 stat  = 0
1462803139.472819 ehci_dump_qtd#12@0: active =0 halted=0 buferr=0 babble=0
1462803139.472819 ehci_dump_qtd#12@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472819 ehci_dump_qtd#12@0: buffer[0] = 0x4137fb84  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472819 ehci_dump_qtd#12@0: buffer[4] = 0
1462803139.472819 ehci_dump_sqtd#11@0: called!
1462803139.472819 ehci_dump_sqtd#11@0: QTD(0xffff800049d61e00) at 0x41397e00:
1462803139.472819 ehci_dump_qtd#13@0: called!
1462803139.472819 ehci_dump_qtd#13@0:      next = 0x00000001  altnext = 0x00000001  status = 0x00008c00
1462803139.472820 ehci_dump_qtd#13@0:    toggle = 0 ioc = 1 bytes = 0 c_page = 0
1462803139.472820 ehci_dump_qtd#13@0:      cerr = 3 pid = 0 stat  = 0
1462803139.472820 ehci_dump_qtd#13@0: active =0 halted=0 buferr=0 babble=0
1462803139.472820 ehci_dump_qtd#13@0: xacterr=0 missed=0 split =0 ping  =0
1462803139.472820 ehci_dump_qtd#13@0: buffer[0] = 0  buffer[1] = 0  buffer[2] = 0  buffer[3] = 0
1462803139.472820 ehci_dump_qtd#13@0: buffer[4] = 0
1462803139.472820 ehci_idone#2@0: --- dump end ---
1462803139.472820 ehci_idone#2@0: len=4 actlen=4 status=0x00008c00
1462803139.472821 ehci_idone#2@0: ex=0xfffffe81076c37d0 done
1462803139.472821 ehci_device_ctrl_done#1@0: called!
1462803139.472821 ehci_device_ctrl_done#1@0: xfer=0xfffffe81076c37d0
1462803139.472821 ehci_device_ctrl_done#1@0: length=4
1462803139.472825 ehci_free_sqtds#1@2: called!
1462803139.472825 ehci_free_sqtds#1@2: exfer=0xfffffe81076c37d0
1462803139.472826 ehci_alloc_sqtd#4@2: called!
1462803139.472826 ehci_alloc_sqtd#5@2: called!
1462803139.472827 ehci_device_ctrl_start#2@2: called!
1462803139.472827 ehci_device_ctrl_start#2@2: type=0x23, request=0x01, wValue=0x0010, wIndex=0x0002
1462803139.472827 ehci_device_ctrl_start#2@2: len=0, addr=2, endpt=0
1462803139.472827 ehci_device_ctrl_start#2@2: setup 0xffff800049d61d80 status 0xffff800049d61e00 data 0x0
1462803139.472827 ehci_device_ctrl_start#2@2: --- dump start ---
1462803139.472827 ehci_dump_sqh#3@2: called!

...