NetBSD-Bugs archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

Re: kern/11018 (VIA VT83C572 UHCI USB controller does not work)



The following reply was made to PR kern/11018; it has been noted by GNATS.

From: Izumi Tsutsui <tsutsui%ceres.dti.ne.jp@localhost>
To: skrll%netbsd.org@localhost
Cc: gnats-bugs%NetBSD.org@localhost, tsutsui%ceres.dti.ne.jp@localhost
Subject: Re: kern/11018 (VIA VT83C572 UHCI USB controller does not work)
Date: Fri, 17 Feb 2017 22:51:47 +0900

 skrll@ wrote:
 
 > I gets further though. Maybe this patch helps more/as well.
 
 Unfortunately gets the same error (with both patches).
 
 ---
 1487337505.-521539122 uhci_poll_hub#33@0: called!
 1487337506.552325780 uhci_poll_hub#34@0: called!
 1487337506.1625986674 uhci_poll_hub#35@0: called!
 1487337506.1626094477 usb_transfer_complete#1@0: called!
 1487337506.1626111656 usb_transfer_complete#1@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487337506.1626144298 usb_transfer_complete#1@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487337506.1626170926 usb_transfer_complete#1@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487337506.1626210440 usb_transfer_complete#1@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487337506.1626270139 usb_needs_explore#1@0: called!
 1487337506.1626404999 usbd_start_next#1@0: called!
 1487337506.1626429480 usbd_start_next#1@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487337506.1626464699 uhci_root_intr_start#1@0: called!
 1487337506.1626481878 uhci_root_intr_start#1@0: xfer=0x3e08ee0 len=1 flags=132
 1487337506.1626700490 usb_event_thread#0@0: sc 0x3ecd0f8 woke up
 1487337506.1626730983 usb_discover#1@0: called!
 1487337506.1626814734 usbd_get_port_status#1@0: called!
 1487337506.1626832773 usbd_get_port_status#1@0: dev 0x3e27298 port 1
 1487337506.1626875293 usbd_do_request_flags#1@0: called!
 1487337506.1626909652 usbd_alloc_xfer#1@0: called!
 1487337506.1627009294 usbd_alloc_xfer#1@0: returns 0x3e08e00
 1487337506.1627052243 usb_allocmem_flags#1@0: called!
 1487337506.1627095622 usb_allocmem_flags#1@0: use frag=0xd5dec0 size=4
 1487337506.1627163482 usbd_transfer#1@0: called!
 1487337506.1627181520 usbd_transfer#1@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337506.1627211585 usbd_dump_queue#1@0: called!
 1487337506.1627228764 usbd_dump_queue#1@0: pipe = 0x3e2d6c8
 1487337506.1627279444 usb_insert_transfer#1@0: called!
 1487337506.1627299630 usb_insert_transfer#1@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337506.1627326259 usb_insert_transfer#1@0: <- done xfer 0x3e08e00, err 0
 1487337506.1627366202 roothub_ctrl_start#1@0: called!
 1487337506.1627383381 roothub_ctrl_start#1@0: type=0xa3 request= 0
 1487337506.1627443081 uhci_roothub_ctrl#1@0: called!
 1487337506.1627458972 uhci_roothub_ctrl#1@0: type=0xa3 request=00
 1487337506.1627508793 uhci_roothub_ctrl#1@0: returning 4
 1487337506.1627528120 roothub_ctrl_start#1@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487337506.1627545729 roothub_ctrl_start#1@0: xfer 0x3e08e00 err 0
 1487337506.1627566774 usb_transfer_complete#2@0: called!
 1487337506.1627575364 usb_transfer_complete#2@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487337506.1627587819 usb_transfer_complete#2@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337506.1627603711 usb_transfer_complete#2@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337506.1627626044 usb_transfer_complete#2@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337506.1627641076 usb_transfer_complete#2@0: <- done xfer 0x3e08e00, wakeup
 1487337506.1627663839 usbd_start_next#2@0: called!
 1487337506.1627676724 usbd_start_next#2@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337506.1627705071 usbd_transfer#1@0: <- done transfer 0x3e08e00, err = 0
 1487337506.1627727834 usbd_transfer#1@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337506.1627766917 usbd_free_xfer#1@0: called!
 1487337506.1627782809 usbd_free_xfer#1@0: 0x3e08e00
 1487337506.1627816738 usb_freemem#1@0: called!
 1487337506.1627848091 usb_freemem#1@0: frag=0xd5dec0
 1487337506.1627961048 usbd_clear_port_feature#1@0: called!
 1487337506.1627979945 usbd_clear_port_feature#1@0: dev 0x3e27298 port 1 sel 16
 1487337506.1628000131 usbd_do_request_flags#2@0: called!
 1487337506.1628011298 usbd_alloc_xfer#2@0: called!
 1487337506.1628038786 usbd_alloc_xfer#2@0: returns 0x3e08e00
 1487337506.1628057683 usbd_transfer#2@0: called!
 1487337506.1628065844 usbd_transfer#2@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337506.1628079158 usbd_dump_queue#2@0: called!
 1487337506.1628088177 usbd_dump_queue#2@0: pipe = 0x3e2d6c8
 1487337506.1628101062 usb_insert_transfer#2@0: called!
 1487337506.1628109652 usb_insert_transfer#2@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337506.1628119530 usb_insert_transfer#2@0: <- done xfer 0x3e08e00, err 0
 1487337506.1628132415 roothub_ctrl_start#2@0: called!
 1487337506.1628144441 roothub_ctrl_start#2@0: type=0x23 request=0x1
 1487337506.1628161191 uhci_roothub_ctrl#2@0: called!
 1487337506.1628169781 uhci_roothub_ctrl#2@0: type=0x23 request=01
 1487337506.1628185672 uhci_roothub_ctrl#2@0: UR_CLEAR_PORT_FEATURE port=1 feature=16
 1487337506.1628217884 uhci_roothub_ctrl#2@0: returning 0
 1487337506.1628226903 roothub_ctrl_start#2@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337506.1628234634 roothub_ctrl_start#2@0: xfer 0x3e08e00 err 0
 1487337506.1628247089 usb_transfer_complete#3@0: called!
 1487337506.1628257397 usb_transfer_complete#3@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337506.1628270711 usb_transfer_complete#3@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337506.1628281019 usb_transfer_complete#3@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337506.1628290468 usb_transfer_complete#3@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337506.1628299917 usb_transfer_complete#3@0: <- done xfer 0x3e08e00, wakeup
 1487337506.1628315378 usbd_start_next#3@0: called!
 1487337506.1628328263 usbd_start_next#3@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337506.1628343725 usbd_transfer#2@0: <- done transfer 0x3e08e00, err = 0
 1487337506.1628355750 usbd_transfer#2@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337506.1628370353 usbd_free_xfer#2@0: called!
 1487337506.1628381949 usbd_free_xfer#2@0: 0x3e08e00
 1487337506.-1595087802 uhci_poll_hub#36@0: called!
 1487337506.-1337406971 usbd_reset_port#1@0: called!
 1487337506.-1337376478 usbd_do_request_flags#3@0: called!
 1487337506.-1337353285 usbd_alloc_xfer#3@0: called!
 1487337506.-1337281560 usbd_alloc_xfer#3@0: returns 0x3e08e00
 1487337506.-1337236893 usbd_transfer#3@0: called!
 1487337506.-1337219284 usbd_transfer#3@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337506.-1337196521 usbd_dump_queue#3@0: called!
 1487337506.-1337187501 usbd_dump_queue#3@0: pipe = 0x3e2d6c8
 1487337506.-1337160443 usb_insert_transfer#3@0: called!
 1487337506.-1337149706 usb_insert_transfer#3@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337506.-1337133385 usb_insert_transfer#3@0: <- done xfer 0x3e08e00, err 0
 1487337506.-1337113199 roothub_ctrl_start#3@0: called!
 1487337506.-1337100314 roothub_ctrl_start#3@0: type=0x23 request=0x3
 1487337506.-1337072397 uhci_roothub_ctrl#3@0: called!
 1487337506.-1337060372 uhci_roothub_ctrl#3@0: type=0x23 request=03
 1487337506.-1337019570 uhci_portreset#1@0: called!
 1487337506.-521578948 uhci_poll_hub#37@0: called!
 1487337506.-521515813 usb_transfer_complete#4@0: called!
 1487337506.-521505076 usb_transfer_complete#4@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487337506.-521488755 usb_transfer_complete#4@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487337506.-521465133 usb_transfer_complete#4@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487337506.-521444517 usb_transfer_complete#4@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487337506.-521402857 usbd_start_next#4@0: called!
 1487337506.-521390401 usbd_start_next#4@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487337506.-521362055 uhci_root_intr_start#2@0: called!
 1487337506.-521344016 uhci_root_intr_start#2@0: xfer=0x3e08ee0 len=1 flags=132
 1487337506.-220756538 uhci_portreset#1@0: uhci port 1 reset, status0 = 0x038a
 1487337506.-220301277 uhci_portreset#1@0: uhci port 1 reset, status1 = 0x01ab
 1487337507.36977550 uhci_portreset#1@0: uhci port 1 iteration 9, status = 0x01af
 1487337507.294576347 uhci_portreset#1@0: uhci port 1 iteration 8, status = 0x01a5
 1487337507.294594815 uhci_portreset#1@0: uhci port 1 reset, status2 = 0x01a5
 1487337507.294630034 roothub_ctrl_start#3@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337507.294642489 roothub_ctrl_start#3@0: xfer 0x3e08e00 err 0
 1487337507.294666111 usb_transfer_complete#5@0: called!
 1487337507.294676419 usb_transfer_complete#5@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337507.294691021 usb_transfer_complete#5@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.294707342 usb_transfer_complete#5@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337507.294721515 usb_transfer_complete#5@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337507.294734830 usb_transfer_complete#5@0: <- done xfer 0x3e08e00, wakeup
 1487337507.294751580 usbd_start_next#5@0: called!
 1487337507.294764035 usbd_start_next#5@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337507.294788087 usbd_transfer#3@0: <- done transfer 0x3e08e00, err = 0
 1487337507.294806555 usbd_transfer#3@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337507.294846927 usbd_free_xfer#3@0: called!
 1487337507.294862818 usbd_free_xfer#3@0: 0x3e08e00
 1487337507.294959024 usbd_reset_port#1@0: port 1 reset done, error=0
 1487337507.552297979 uhci_poll_hub#38@0: called!
 1487337507.552532482 usbd_get_port_status#2@0: called!
 1487337507.552547944 usbd_get_port_status#2@0: dev 0x3e27298 port 1
 1487337507.552570277 usbd_do_request_flags#4@0: called!
 1487337507.552589604 usbd_alloc_xfer#4@0: called!
 1487337507.552662188 usbd_alloc_xfer#4@0: returns 0x3e08e00
 1487337507.552699125 usb_allocmem_flags#2@0: called!
 1487337507.552736490 usb_allocmem_flags#2@0: use frag=0xd5dec0 size=4
 1487337507.552784164 usbd_transfer#4@0: called!
 1487337507.552797478 usbd_transfer#4@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337507.552815087 usbd_dump_queue#4@0: called!
 1487337507.552825825 usbd_dump_queue#4@0: pipe = 0x3e2d6c8
 1487337507.552850735 usb_insert_transfer#4@0: called!
 1487337507.552859325 usb_insert_transfer#4@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337507.552876934 usb_insert_transfer#4@0: <- done xfer 0x3e08e00, err 0
 1487337507.552897979 roothub_ctrl_start#4@0: called!
 1487337507.552909146 roothub_ctrl_start#4@0: type=0xa3 request= 0
 1487337507.552934916 uhci_roothub_ctrl#4@0: called!
 1487337507.552948659 uhci_roothub_ctrl#4@0: type=0xa3 request=00
 1487337507.552975717 uhci_roothub_ctrl#4@0: returning 4
 1487337507.552988602 roothub_ctrl_start#4@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487337507.552996762 roothub_ctrl_start#4@0: xfer 0x3e08e00 err 0
 1487337507.553016519 usb_transfer_complete#6@0: called!
 1487337507.553027686 usb_transfer_complete#6@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487337507.553043577 usb_transfer_complete#6@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.553055603 usb_transfer_complete#6@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337507.553075789 usb_transfer_complete#6@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337507.553088674 usb_transfer_complete#6@0: <- done xfer 0x3e08e00, wakeup
 1487337507.553110148 usbd_start_next#6@0: called!
 1487337507.553122603 usbd_start_next#6@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337507.553141931 usbd_transfer#4@0: <- done transfer 0x3e08e00, err = 0
 1487337507.553154386 usbd_transfer#4@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337507.553174572 usbd_free_xfer#4@0: called!
 1487337507.553183162 usbd_free_xfer#4@0: 0x3e08e00
 1487337507.553211079 usb_freemem#2@0: called!
 1487337507.553232983 usb_freemem#2@0: frag=0xd5dec0
 1487337507.553316304 usbd_clear_port_feature#2@0: called!
 1487337507.553324894 usbd_clear_port_feature#2@0: dev 0x3e27298 port 1 sel 20
 1487337507.553339497 usbd_do_request_flags#5@0: called!
 1487337507.553351093 usbd_alloc_xfer#5@0: called!
 1487337507.553379439 usbd_alloc_xfer#5@0: returns 0x3e08e00
 1487337507.553394901 usbd_transfer#5@0: called!
 1487337507.553403920 usbd_transfer#5@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337507.553417664 usbd_dump_queue#5@0: called!
 1487337507.553428831 usbd_dump_queue#5@0: pipe = 0x3e2d6c8
 1487337507.553439568 usb_insert_transfer#5@0: called!
 1487337507.553446870 usb_insert_transfer#5@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337507.553456748 usb_insert_transfer#5@0: <- done xfer 0x3e08e00, err 0
 1487337507.553470062 roothub_ctrl_start#5@0: called!
 1487337507.553480370 roothub_ctrl_start#5@0: type=0x23 request=0x1
 1487337507.553494973 uhci_roothub_ctrl#5@0: called!
 1487337507.553502274 uhci_roothub_ctrl#5@0: type=0x23 request=01
 1487337507.553515588 uhci_roothub_ctrl#5@0: UR_CLEAR_PORT_FEATURE port=1 feature=20
 1487337507.553534486 uhci_roothub_ctrl#5@0: returning 0
 1487337507.553546082 roothub_ctrl_start#5@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337507.553554672 roothub_ctrl_start#5@0: xfer 0x3e08e00 err 0
 1487337507.553569275 usb_transfer_complete#7@0: called!
 1487337507.553577865 usb_transfer_complete#7@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337507.553592038 usb_transfer_complete#7@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.553602775 usb_transfer_complete#7@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337507.553613942 usb_transfer_complete#7@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337507.553621673 usb_transfer_complete#7@0: <- done xfer 0x3e08e00, wakeup
 1487337507.553636275 usbd_start_next#7@0: called!
 1487337507.553647872 usbd_start_next#7@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337507.553665481 usbd_transfer#5@0: <- done transfer 0x3e08e00, err = 0
 1487337507.553673212 usbd_transfer#5@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337507.553686526 usbd_free_xfer#5@0: called!
 1487337507.553697693 usbd_free_xfer#5@0: 0x3e08e00
 1487337507.1625948994 uhci_poll_hub#39@0: called!
 1487337507.1669041182 usbd_new_device#1@0: called!
 1487337507.1669060509 usbd_new_device#1@0: bus=0x3e3200c port=1 depth=1 speed=1
 1487337507.1669190216 usbd_setup_pipe_flags#1@0: called!
 1487337507.1669248197 usbd_setup_pipe_flags#1@0: dev=0x375d7c0 addr=0 iface=0x0 ep=0x375d7e4 pipe=0xfdc04427
 1487337507.1669285563 uhci_open#1@0: called!
 1487337507.1669302742 uhci_open#1@0: pipe=0x32c3748, addr=0, endpt=0 (1)
 1487337507.1669340538 uhci_alloc_sqh#1@0: called!
 1487337507.1669381339 uhci_alloc_std#1@0: called!
 1487337507.1669409256 uhci_alloc_std#2@0: called!
 1487337507.1669442327 usb_allocmem_flags#3@0: called!
 1487337507.1669471962 usb_allocmem_flags#3@0: use frag=0xd5dec0 size=8
 1487337507.1669501168 usbd_setup_pipe_flags#1@0: pipe=0x32c3748
 1487337507.1669536815 usbd_get_initial_ddesc#1@0: called!
 1487337507.1669553136 usbd_get_initial_ddesc#1@0: dev 0x375d7c0
 1487337507.1669581053 usbd_do_request_flags#6@0: called!
 1487337507.1669601239 usbd_alloc_xfer#6@0: called!
 1487337507.1669662656 usbd_alloc_xfer#6@0: returns 0x3e08e00
 1487337507.1669679836 usb_allocmem_flags#4@0: called!
 1487337507.1669691862 usb_allocmem_flags#4@0: use frag=0xd5de80 size=64
 1487337507.1669723215 uhci_device_ctrl_init#1@0: called!
 1487337507.1669737388 uhci_device_ctrl_init#1@0: xfer=0x3e08e00 len=64, addr=0, endpt=0
 1487337507.1669775183 uhci_alloc_std_chain#1@0: called!
 1487337507.1669793651 uhci_alloc_std_chain#1@0: xfer=0x3e08e00 pipe=0x32c3748
 1487337507.1669813408 uhci_alloc_std_chain#1@0: maxp=8 ntd=8
 1487337507.1669868812 uhci_alloc_std#3@0: called!
 1487337507.1669883415 uhci_alloc_std#4@0: called!
 1487337507.1669899306 uhci_alloc_std#5@0: called!
 1487337507.1669913909 uhci_alloc_std#6@0: called!
 1487337507.1669928941 uhci_alloc_std#7@0: called!
 1487337507.1669944403 uhci_alloc_std#8@0: called!
 1487337507.1669959006 uhci_alloc_std#9@0: called!
 1487337507.1669973179 uhci_alloc_std#10@0: called!
 1487337507.1670020852 usbd_transfer#6@0: called!
 1487337507.1670038032 usbd_transfer#6@0: xfer = 0x3e08e00, flags = 0x6, pipe = 0x32c3748, running = 0
 1487337507.1670054782 usbd_dump_queue#6@0: called!
 1487337507.1670065090 usbd_dump_queue#6@0: pipe = 0x32c3748
 1487337507.1670089571 usb_insert_transfer#6@0: called!
 1487337507.1670102456 usb_insert_transfer#6@0: xfer = 0x3e08e00 pipe = 0x32c3748 running = 0 timeout = 5000
 1487337507.1670119206 usb_insert_transfer#6@0: <- done xfer 0x3e08e00, err 0
 1487337507.1670155283 uhci_device_ctrl_start#1@0: called!
 1487337507.1670176758 uhci_device_ctrl_start#1@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487337507.1670197374 uhci_device_ctrl_start#1@0: len=64, addr=0, endpt=0
 1487337507.1670247195 uhci_reset_std_chain#1@0: called!
 1487337507.1670265663 uhci_reset_std_chain#1@0: xfer=0x3e08e00 len 64 isread 128 toggle 1
 1487337507.1670378619 uhci_device_ctrl_start#1@0: --- dump start ---
 1487337507.1670397517 uhci_device_ctrl_start#1@0: before transfer
 1487337507.1670429299 uhci_dump_td#1@0: called!
 1487337507.1670449915 uhci_dump_td#1@0: TD(0xd24770) at 0x00d24770
 1487337507.1670466665 uhci_dump_td#1@0:    link=0x00d245f0 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487337507.1670483415 uhci_dump_td#1@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670504890 uhci_dump_td#1@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670525935 uhci_dump_td#1@0: ios     =0 ls      =1 spd     =0
 1487337507.1670541826 uhci_dump_td#1@0: errcnt  =3 actlen  =1024 pid=2d
 1487337507.1670562012 uhci_dump_td#1@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1670589070 uhci_dump_td#2@0: called!
 1487337507.1670597660 uhci_dump_td#2@0: TD(0xd245f0) at 0x00d245f0
 1487337507.1670604102 uhci_dump_td#2@0:    link=0x00d24624 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487337507.1670612692 uhci_dump_td#2@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670620852 uhci_dump_td#2@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670628583 uhci_dump_td#2@0: ios     =0 ls      =1 spd     =1
 1487337507.1670635026 uhci_dump_td#2@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670645333 uhci_dump_td#2@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1670656930 uhci_dump_td#3@0: called!
 1487337507.1670665519 uhci_dump_td#3@0: TD(0xd24620) at 0x00d24620
 1487337507.1670671962 uhci_dump_td#3@0:    link=0x00d24654 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de88
 1487337507.1670680552 uhci_dump_td#3@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670688712 uhci_dump_td#3@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670696872 uhci_dump_td#3@0: ios     =0 ls      =1 spd     =1
 1487337507.1670703315 uhci_dump_td#3@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670713193 uhci_dump_td#3@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1670724789 uhci_dump_td#4@0: called!
 1487337507.1670733379 uhci_dump_td#4@0: TD(0xd24650) at 0x00d24650
 1487337507.1670739822 uhci_dump_td#4@0:    link=0x00d24684 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de90
 1487337507.1670747552 uhci_dump_td#4@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670755713 uhci_dump_td#4@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670763873 uhci_dump_td#4@0: ios     =0 ls      =1 spd     =1
 1487337507.1670770315 uhci_dump_td#4@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670780623 uhci_dump_td#4@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1670790931 uhci_dump_td#5@0: called!
 1487337507.1670799091 uhci_dump_td#5@0: TD(0xd24680) at 0x00d24680
 1487337507.1670805534 uhci_dump_td#5@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487337507.1670814124 uhci_dump_td#5@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670822284 uhci_dump_td#5@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670830444 uhci_dump_td#5@0: ios     =0 ls      =1 spd     =1
 1487337507.1670836457 uhci_dump_td#5@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670846765 uhci_dump_td#5@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1670857073 uhci_dump_td#6@0: called!
 1487337507.1670865233 uhci_dump_td#6@0: TD(0xd246b0) at 0x00d246b0
 1487337507.1670872105 uhci_dump_td#6@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487337507.1670881124 uhci_dump_td#6@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670889285 uhci_dump_td#6@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670897445 uhci_dump_td#6@0: ios     =0 ls      =1 spd     =1
 1487337507.1670903887 uhci_dump_td#6@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670914195 uhci_dump_td#6@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1670924503 uhci_dump_td#7@0: called!
 1487337507.1670933093 uhci_dump_td#7@0: TD(0xd246e0) at 0x00d246e0
 1487337507.1670938676 uhci_dump_td#7@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487337507.1670947266 uhci_dump_td#7@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1670955426 uhci_dump_td#7@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1670963587 uhci_dump_td#7@0: ios     =0 ls      =1 spd     =1
 1487337507.1670969170 uhci_dump_td#7@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1670978619 uhci_dump_td#7@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1670988927 uhci_dump_td#8@0: called!
 1487337507.1670997517 uhci_dump_td#8@0: TD(0xd24710) at 0x00d24710
 1487337507.1671003959 uhci_dump_td#8@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487337507.1671013408 uhci_dump_td#8@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671021568 uhci_dump_td#8@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671029728 uhci_dump_td#8@0: ios     =0 ls      =1 spd     =1
 1487337507.1671036171 uhci_dump_td#8@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671043902 uhci_dump_td#8@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1671054209 uhci_dump_td#9@0: called!
 1487337507.1671062370 uhci_dump_td#9@0: TD(0xd24740) at 0x00d24740
 1487337507.1671068383 uhci_dump_td#9@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487337507.1671078261 uhci_dump_td#9@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671085992 uhci_dump_td#9@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671094152 uhci_dump_td#9@0: ios     =0 ls      =1 spd     =1
 1487337507.1671101024 uhci_dump_td#9@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671110043 uhci_dump_td#9@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1671121640 uhci_dump_td#10@0: called!
 1487337507.1671129800 uhci_dump_td#10@0: TD(0xd247a0) at 0x00d247a0
 1487337507.1671136242 uhci_dump_td#10@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487337507.1671146121 uhci_dump_td#10@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671153852 uhci_dump_td#10@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337507.1671162012 uhci_dump_td#10@0: ios     =0 ls      =1 spd     =0
 1487337507.1671168884 uhci_dump_td#10@0: errcnt  =3 actlen  =1024 pid=e1
 1487337507.1671177903 uhci_dump_td#10@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.1671195512 uhci_device_ctrl_start#1@0: --- dump end ---
 1487337507.1671227724 uhci_add_ls_ctrl#1@0: called!
 1487337507.1671241468 uhci_add_ls_ctrl#1@0: sqh 0xd22710
 1487337507.1671283988 uhci_device_ctrl_start#1@0: --- dump start ---
 1487337507.1671301167 uhci_device_ctrl_start#1@0: follow from [0]
 1487337507.1671319206 uhci_dump_td#11@0: called!
 1487337507.1671332520 uhci_dump_td#11@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487337507.1671341969 uhci_dump_td#11@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487337507.1671350129 uhci_dump_td#11@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671357860 uhci_dump_td#11@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.1671363873 uhci_dump_td#11@0: ios     =1 ls      =0 spd     =0
 1487337507.1671372892 uhci_dump_td#11@0: errcnt  =0 actlen  =1 pid=00
 1487337507.1671381053 uhci_dump_td#11@0: addr=0  endpt=0  D=0  maxlen=1,
 1487337507.1671405534 uhci_dump_qh#1@0: called!
 1487337507.1671427008 uhci_dump_qh#1@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337507.1671448483 uhci_dump_qh#2@0: called!
 1487337507.1671457932 uhci_dump_qh#2@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337507.1671471246 uhci_dump_qh#3@0: called!
 1487337507.1671477688 uhci_dump_qh#3@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487337507.1671487137 uhci_dump_qh#4@0: called!
 1487337507.1671495297 uhci_dump_qh#4@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337507.1671504746 uhci_dump_qh#5@0: called!
 1487337507.1671514195 uhci_dump_qh#5@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487337507.1671523644 uhci_dump_qh#6@0: called!
 1487337507.1671539106 uhci_dump_qh#6@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487337507.1671548554 uhci_dump_qh#7@0: called!
 1487337507.1671558003 uhci_dump_qh#7@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487337507.1671573894 uhci_device_ctrl_start#1@0: Enqueued QH:
 1487337507.1671586350 uhci_dump_qh#8@0: called!
 1487337507.1671594939 uhci_dump_qh#8@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337507.1671602670 uhci_dump_td#12@0: called!
 1487337507.1671612549 uhci_dump_td#12@0: TD(0xd24770) at 0x00d24770
 1487337507.1671620709 uhci_dump_td#12@0:    link=0x00d245f0 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487337507.1671628869 uhci_dump_td#12@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671635312 uhci_dump_td#12@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671644761 uhci_dump_td#12@0: ios     =0 ls      =1 spd     =0
 1487337507.1671652921 uhci_dump_td#12@0: errcnt  =3 actlen  =1024 pid=2d
 1487337507.1671662370 uhci_dump_td#12@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1671670530 uhci_dump_td#13@0: called!
 1487337507.1671679549 uhci_dump_td#13@0: TD(0xd245f0) at 0x00d245f0
 1487337507.1671687710 uhci_dump_td#13@0:    link=0x00d24624 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487337507.1671695870 uhci_dump_td#13@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671702312 uhci_dump_td#13@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671710902 uhci_dump_td#13@0: ios     =0 ls      =1 spd     =1
 1487337507.1671719063 uhci_dump_td#13@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671726793 uhci_dump_td#13@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1671734954 uhci_dump_td#14@0: called!
 1487337507.1671744832 uhci_dump_td#14@0: TD(0xd24620) at 0x00d24620
 1487337507.1671753851 uhci_dump_td#14@0:    link=0x00d24654 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de88
 1487337507.1671762012 uhci_dump_td#14@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671768884 uhci_dump_td#14@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671777473 uhci_dump_td#14@0: ios     =0 ls      =1 spd     =1
 1487337507.1671785204 uhci_dump_td#14@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671793794 uhci_dump_td#14@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1671801954 uhci_dump_td#15@0: called!
 1487337507.1671811403 uhci_dump_td#15@0: TD(0xd24650) at 0x00d24650
 1487337507.1671819134 uhci_dump_td#15@0:    link=0x00d24684 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de90
 1487337507.1671826865 uhci_dump_td#15@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671832878 uhci_dump_td#15@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671842327 uhci_dump_td#15@0: ios     =0 ls      =1 spd     =1
 1487337507.1671850487 uhci_dump_td#15@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671858218 uhci_dump_td#15@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1671866808 uhci_dump_td#16@0: called!
 1487337507.1671874539 uhci_dump_td#16@0: TD(0xd24680) at 0x00d24680
 1487337507.1671882699 uhci_dump_td#16@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487337507.1671891289 uhci_dump_td#16@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671897302 uhci_dump_td#16@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671905891 uhci_dump_td#16@0: ios     =0 ls      =1 spd     =1
 1487337507.1671914052 uhci_dump_td#16@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671922212 uhci_dump_td#16@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1671930802 uhci_dump_td#17@0: called!
 1487337507.1671941110 uhci_dump_td#17@0: TD(0xd246b0) at 0x00d246b0
 1487337507.1671950129 uhci_dump_td#17@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487337507.1671959148 uhci_dump_td#17@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1671965591 uhci_dump_td#17@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1671975040 uhci_dump_td#17@0: ios     =0 ls      =1 spd     =1
 1487337507.1671983200 uhci_dump_td#17@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1671991360 uhci_dump_td#17@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1671999950 uhci_dump_td#18@0: called!
 1487337507.1672010258 uhci_dump_td#18@0: TD(0xd246e0) at 0x00d246e0
 1487337507.1672018418 uhci_dump_td#18@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487337507.1672026579 uhci_dump_td#18@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1672033450 uhci_dump_td#18@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1672042040 uhci_dump_td#18@0: ios     =0 ls      =1 spd     =1
 1487337507.1672049771 uhci_dump_td#18@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1672057502 uhci_dump_td#18@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1672066092 uhci_dump_td#19@0: called!
 1487337507.1672075541 uhci_dump_td#19@0: TD(0xd24710) at 0x00d24710
 1487337507.1672083272 uhci_dump_td#19@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487337507.1672091002 uhci_dump_td#19@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1672097874 uhci_dump_td#19@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1672106464 uhci_dump_td#19@0: ios     =0 ls      =1 spd     =1
 1487337507.1672114195 uhci_dump_td#19@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1672122355 uhci_dump_td#19@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1672130516 uhci_dump_td#20@0: called!
 1487337507.1672139105 uhci_dump_td#20@0: TD(0xd24740) at 0x00d24740
 1487337507.1672147266 uhci_dump_td#20@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487337507.1672155426 uhci_dump_td#20@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1672162298 uhci_dump_td#20@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1672171317 uhci_dump_td#20@0: ios     =0 ls      =1 spd     =1
 1487337507.1672179478 uhci_dump_td#20@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1672187638 uhci_dump_td#20@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1672195798 uhci_dump_td#21@0: called!
 1487337507.1672207824 uhci_dump_td#21@0: TD(0xd247a0) at 0x00d247a0
 1487337507.1672215984 uhci_dump_td#21@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487337507.1672224574 uhci_dump_td#21@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1672231017 uhci_dump_td#21@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337507.1672240465 uhci_dump_td#21@0: ios     =0 ls      =1 spd     =0
 1487337507.1672248626 uhci_dump_td#21@0: errcnt  =3 actlen  =1024 pid=e1
 1487337507.1672256786 uhci_dump_td#21@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.1672269241 uhci_device_ctrl_start#1@0: --- dump end ---
 1487337507.1672357287 usbd_transfer#6@0: <- done transfer 0x3e08e00, err = 1
 1487337507.1672385204 usbd_transfer#6@0: <- sleeping on xfer 0x3e08e00
 1487337507.1681527364 uhci_intr#1@0: called!
 1487337507.1681576326 uhci_intr1#1@0: called!
 1487337507.1681595224 uhci_intr1#1@0: sc 0x3e32008
 1487337507.1681624429 uhci_dumpregs#1@0: called!
 1487337507.1681642468 uhci_dumpregs#1@0: cmd =0081  sts    =0001  intr   =000f  frnum =04a6
 1487337507.1681668237 uhci_dumpregs#1@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487337507.1681733949 usb_schedsoftintr#1@0: called!
 1487337507.1681751988 usb_schedsoftintr#1@0: polling=0
 1487337507.1681802239 uhci_intr1#1@0: sc 0x3e32008 done
 1487337507.1681933663 uhci_softintr#1@0: called!
 1487337507.1681950843 uhci_softintr#1@0: sc 0x3e32008
 1487337507.1681992503 uhci_check_intr#1@0: called!
 1487337507.1682009683 uhci_check_intr#1@0: ux 0x3e08e00
 1487337507.1682036312 uhci_check_intr#1@0: active ux=0x3e08e00
 1487337507.1682076684 uhci_check_intr#1@0: ux=0x3e08e00 done
 1487337507.1682139390 uhci_idone#1@0: called!
 1487337507.1682156569 uhci_idone#1@0: ux=0x3e08e00
 1487337507.1682179332 uhci_idone#1@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x32c3748 ready
 1487337507.1682198659 uhci_idone#1@0: --- dump start ---
 1487337507.1682217987 uhci_dump_td#22@0: called!
 1487337507.1682230012 uhci_dump_td#22@0: TD(0xd24770) at 0x00d24770
 1487337507.1682237314 uhci_dump_td#22@0:    link=0x00d245f0 status=0x1c000007 token=0x00e0002d buffer=0x00d5dec0
 1487337507.1682251057 uhci_dump_td#22@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682269526 uhci_dump_td#22@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.1682281981 uhci_dump_td#22@0: ios     =0 ls      =1 spd     =0
 1487337507.1682289712 uhci_dump_td#22@0: errcnt  =3 actlen  =8 pid=2d
 1487337507.1682301737 uhci_dump_td#22@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1682317629 uhci_dump_td#23@0: called!
 1487337507.1682325789 uhci_dump_td#23@0: TD(0xd245f0) at 0x00d245f0
 1487337507.1682332661 uhci_dump_td#23@0:    link=0x00d24624 status=0x1c000007 token=0x00e80069 buffer=0x00d5de80
 1487337507.1682342969 uhci_dump_td#23@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682351129 uhci_dump_td#23@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.1682359289 uhci_dump_td#23@0: ios     =0 ls      =1 spd     =0
 1487337507.1682364873 uhci_dump_td#23@0: errcnt  =3 actlen  =8 pid=69
 1487337507.1682373892 uhci_dump_td#23@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1682384200 uhci_dump_td#24@0: called!
 1487337507.1682392790 uhci_dump_td#24@0: TD(0xd24620) at 0x00d24620
 1487337507.1682399232 uhci_dump_td#24@0:    link=0x00d24654 status=0x1c000007 token=0x00e00069 buffer=0x00d5de88
 1487337507.1682408681 uhci_dump_td#24@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682416841 uhci_dump_td#24@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.1682424572 uhci_dump_td#24@0: ios     =0 ls      =1 spd     =0
 1487337507.1682430585 uhci_dump_td#24@0: errcnt  =3 actlen  =8 pid=69
 1487337507.1682438745 uhci_dump_td#24@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1682449483 uhci_dump_td#25@0: called!
 1487337507.1682458502 uhci_dump_td#25@0: TD(0xd24650) at 0x00d24650
 1487337507.1682466233 uhci_dump_td#25@0:    link=0x00d24684 status=0x1c4007ff token=0x00e80069 buffer=0x00d5de90
 1487337507.1682476540 uhci_dump_td#25@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682484701 uhci_dump_td#25@0: dbuffer =0 stalled =1 active  =0 ioc     =0
 1487337507.1682492432 uhci_dump_td#25@0: ios     =0 ls      =1 spd     =0
 1487337507.1682498874 uhci_dump_td#25@0: errcnt  =3 actlen  =0 pid=69
 1487337507.1682508323 uhci_dump_td#25@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1682518631 uhci_dump_td#26@0: called!
 1487337507.1682528079 uhci_dump_td#26@0: TD(0xd24680) at 0x00d24680
 1487337507.1682534092 uhci_dump_td#26@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487337507.1682544400 uhci_dump_td#26@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682552561 uhci_dump_td#26@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1682560721 uhci_dump_td#26@0: ios     =0 ls      =1 spd     =1
 1487337507.1682567163 uhci_dump_td#26@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1682576612 uhci_dump_td#26@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1682586920 uhci_dump_td#27@0: called!
 1487337507.1682595939 uhci_dump_td#27@0: TD(0xd246b0) at 0x00d246b0
 1487337507.1682602811 uhci_dump_td#27@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487337507.1682613119 uhci_dump_td#27@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682621279 uhci_dump_td#27@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1682629440 uhci_dump_td#27@0: ios     =0 ls      =1 spd     =1
 1487337507.1682635882 uhci_dump_td#27@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1682645331 uhci_dump_td#27@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1682655639 uhci_dump_td#28@0: called!
 1487337507.1682663799 uhci_dump_td#28@0: TD(0xd246e0) at 0x00d246e0
 1487337507.1682670671 uhci_dump_td#28@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487337507.1682680979 uhci_dump_td#28@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682689139 uhci_dump_td#28@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1682697299 uhci_dump_td#28@0: ios     =0 ls      =1 spd     =1
 1487337507.1682702883 uhci_dump_td#28@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1682711472 uhci_dump_td#28@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1682721780 uhci_dump_td#29@0: called!
 1487337507.1682730800 uhci_dump_td#29@0: TD(0xd24710) at 0x00d24710
 1487337507.1682738530 uhci_dump_td#29@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487337507.1682748838 uhci_dump_td#29@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682756999 uhci_dump_td#29@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1682765159 uhci_dump_td#29@0: ios     =0 ls      =1 spd     =1
 1487337507.1682771601 uhci_dump_td#29@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1682781050 uhci_dump_td#29@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.1682791358 uhci_dump_td#30@0: called!
 1487337507.1682799518 uhci_dump_td#30@0: TD(0xd24740) at 0x00d24740
 1487337507.1682806390 uhci_dump_td#30@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487337507.1682816698 uhci_dump_td#30@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682824858 uhci_dump_td#30@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.1682833019 uhci_dump_td#30@0: ios     =0 ls      =1 spd     =1
 1487337507.1682839461 uhci_dump_td#30@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.1682848910 uhci_dump_td#30@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.1682859218 uhci_dump_td#31@0: called!
 1487337507.1682866948 uhci_dump_td#31@0: TD(0xd247a0) at 0x00d247a0
 1487337507.1682874250 uhci_dump_td#31@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487337507.1682884558 uhci_dump_td#31@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1682892718 uhci_dump_td#31@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337507.1682900878 uhci_dump_td#31@0: ios     =0 ls      =1 spd     =0
 1487337507.1682907321 uhci_dump_td#31@0: errcnt  =3 actlen  =1024 pid=e1
 1487337507.1682916769 uhci_dump_td#31@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.1682933520 uhci_idone#1@0: --- dump end ---
 1487337507.1682967020 uhci_idone#1@0: actlen=16, status=0x400000
 1487337507.1682985488 uhci_idone#1@0: error, addr=0, endpt=0x00
 1487337507.1683007822 uhci_idone#1@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.1683029726 uhci_idone#1@0: dbuffer =0 stalled =1 active  =0
 1487337507.1683056354 uhci_idone#1@0: ux=0x3e08e00 done
 1487337507.1683081694 uhci_softintr#1@0: ux 0x3e08e00
 1487337507.1683105316 usb_transfer_complete#8@0: called!
 1487337507.1683116483 usb_transfer_complete#8@0: pipe = 0x32c3748 xfer = 0x3e08e00 status = 17 actlen = 16
 1487337507.1683134522 usb_transfer_complete#8@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.1683146548 usb_transfer_complete#8@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487337507.1683182195 uhci_device_ctrl_done#1@0: called!
 1487337507.1683222568 uhci_remove_ls_ctrl#1@0: called!
 1487337507.1683239747 uhci_remove_ls_ctrl#1@0: sqh 0xd22710
 1487337507.1683296011 uhci_find_prev_qh#1@0: called!
 1487337507.1683312761 uhci_find_prev_qh#1@0: pqh=0xd20740 sqh=0xd22710
 1487337507.1683370742 uhci_device_ctrl_done#1@0: length=16
 1487337507.1683403813 usb_transfer_complete#8@0: xfer 0x3e08e00 doing callback 0x0 status 17
 1487337507.1683415839 usb_transfer_complete#8@0: <- done xfer 0x3e08e00, wakeup
 1487337507.1683539532 usbd_start_next#8@0: called!
 1487337507.1683554135 usbd_start_next#8@0: pipe = 0x32c3748, xfer = 0x0
 1487337507.1683784772 uhci_free_stds#1@0: called!
 1487337507.1683799375 uhci_free_stds#1@0: ux=0x3e08e00
 1487337507.1683915338 usbd_free_xfer#6@0: called!
 1487337507.1683926504 usbd_free_xfer#6@0: 0x3e08e00
 1487337507.1683952274 usb_freemem#3@0: called!
 1487337507.1683975466 usb_freemem#3@0: frag=0xd5de80
 1487337507.1684035166 usbd_do_request_flags#6@0: returning err = 17
 1487337507.1685759575 uhci_intr#2@0: called!
 1487337507.1685787062 uhci_intr1#2@0: called!
 1487337507.1685796511 uhci_intr1#2@0: sc 0x3e32008
 1487337507.1685814979 uhci_dumpregs#2@0: called!
 1487337507.1685826146 uhci_dumpregs#2@0: cmd =0081  sts    =0002  intr   =000f  frnum =04a7
 1487337507.1685847621 uhci_dumpregs#2@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487337507.1685882409 usb_schedsoftintr#2@0: called!
 1487337507.1685895724 usb_schedsoftintr#2@0: polling=0
 1487337507.1685927077 uhci_intr1#2@0: sc 0x3e32008 done
 1487337507.1686003956 uhci_softintr#2@0: called!
 1487337507.1686013404 uhci_softintr#2@0: sc 0x3e32008
 1487337507.-1723250151 usbd_get_initial_ddesc#2@0: called!
 1487337507.-1723227817 usbd_get_initial_ddesc#2@0: dev 0x375d7c0
 1487337507.-1723179714 usbd_do_request_flags#7@0: called!
 1487337507.-1723143637 usbd_alloc_xfer#7@0: called!
 1487337507.-1723050008 usbd_alloc_xfer#7@0: returns 0x3e08e00
 1487337507.-1723010065 usb_allocmem_flags#5@0: called!
 1487337507.-1722968404 usb_allocmem_flags#5@0: use frag=0xd5de80 size=8
 1487337507.-1722919442 uhci_device_ctrl_init#2@0: called!
 1487337507.-1722902263 uhci_device_ctrl_init#2@0: xfer=0x3e08e00 len=8, addr=0, endpt=0
 1487337507.-1722857166 uhci_alloc_std_chain#2@0: called!
 1487337507.-1722839986 uhci_alloc_std_chain#2@0: xfer=0x3e08e00 pipe=0x32c3748
 1487337507.-1722820659 uhci_alloc_std_chain#2@0: maxp=8 ntd=1
 1487337507.-1722727889 uhci_alloc_std#11@0: called!
 1487337507.-1722643279 usbd_transfer#7@0: called!
 1487337507.-1722626100 usbd_transfer#7@0: xfer = 0x3e08e00, flags = 0x6, pipe = 0x32c3748, running = 0
 1487337507.-1722600330 usbd_dump_queue#7@0: called!
 1487337507.-1722581432 usbd_dump_queue#7@0: pipe = 0x32c3748
 1487337507.-1722534618 usb_insert_transfer#7@0: called!
 1487337507.-1722516150 usb_insert_transfer#7@0: xfer = 0x3e08e00 pipe = 0x32c3748 running = 0 timeout = 5000
 1487337507.-1722491239 usb_insert_transfer#7@0: <- done xfer 0x3e08e00, err 0
 1487337507.-1722448290 uhci_device_ctrl_start#2@0: called!
 1487337507.-1722427674 uhci_device_ctrl_start#2@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487337507.-1722410065 uhci_device_ctrl_start#2@0: len=8, addr=0, endpt=0
 1487337507.-1722360244 uhci_reset_std_chain#2@0: called!
 1487337507.-1722341776 uhci_reset_std_chain#2@0: xfer=0x3e08e00 len 8 isread 128 toggle 1
 1487337507.-1722226672 uhci_device_ctrl_start#2@0: --- dump start ---
 1487337507.-1722209493 uhci_device_ctrl_start#2@0: before transfer
 1487337507.-1722176422 uhci_dump_td#32@0: called!
 1487337507.-1722155806 uhci_dump_td#32@0: TD(0xd24770) at 0x00d24770
 1487337507.-1722138197 uhci_dump_td#32@0:    link=0x00d24740 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487337507.-1722118011 uhci_dump_td#32@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1722096536 uhci_dump_td#32@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.-1722076780 uhci_dump_td#32@0: ios     =0 ls      =1 spd     =0
 1487337507.-1722059600 uhci_dump_td#32@0: errcnt  =3 actlen  =1024 pid=2d
 1487337507.-1722038555 uhci_dump_td#32@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.-1722016221 uhci_dump_td#33@0: called!
 1487337507.-1722007632 uhci_dump_td#33@0: TD(0xd24740) at 0x00d24740
 1487337507.-1722000330 uhci_dump_td#33@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487337507.-1721992170 uhci_dump_td#33@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721985298 uhci_dump_td#33@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.-1721977138 uhci_dump_td#33@0: ios     =0 ls      =1 spd     =1
 1487337507.-1721968118 uhci_dump_td#33@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.-1721959958 uhci_dump_td#33@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.-1721950939 uhci_dump_td#34@0: called!
 1487337507.-1721941919 uhci_dump_td#34@0: TD(0xd247a0) at 0x00d247a0
 1487337507.-1721934189 uhci_dump_td#34@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487337507.-1721925169 uhci_dump_td#34@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721917009 uhci_dump_td#34@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337507.-1721907560 uhci_dump_td#34@0: ios     =0 ls      =1 spd     =0
 1487337507.-1721898970 uhci_dump_td#34@0: errcnt  =3 actlen  =1024 pid=e1
 1487337507.-1721890810 uhci_dump_td#34@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.-1721878355 uhci_device_ctrl_start#2@0: --- dump end ---
 1487337507.-1721833258 uhci_add_ls_ctrl#2@0: called!
 1487337507.-1721816078 uhci_add_ls_ctrl#2@0: sqh 0xd22710
 1487337507.-1721776565 uhci_device_ctrl_start#2@0: --- dump start ---
 1487337507.-1721759815 uhci_device_ctrl_start#2@0: follow from [0]
 1487337507.-1721742635 uhci_dump_td#35@0: called!
 1487337507.-1721730180 uhci_dump_td#35@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487337507.-1721722020 uhci_dump_td#35@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487337507.-1721715148 uhci_dump_td#35@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721706128 uhci_dump_td#35@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.-1721697109 uhci_dump_td#35@0: ios     =1 ls      =0 spd     =0
 1487337507.-1721688949 uhci_dump_td#35@0: errcnt  =0 actlen  =1 pid=00
 1487337507.-1721682936 uhci_dump_td#35@0: addr=0  endpt=0  D=0  maxlen=1,
 1487337507.-1721659314 uhci_dump_qh#9@0: called!
 1487337507.-1721636980 uhci_dump_qh#9@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337507.-1721615935 uhci_dump_qh#10@0: called!
 1487337507.-1721609493 uhci_dump_qh#10@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337507.-1721597038 uhci_dump_qh#11@0: called!
 1487337507.-1721589307 uhci_dump_qh#11@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487337507.-1721578999 uhci_dump_qh#12@0: called!
 1487337507.-1721571268 uhci_dump_qh#12@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337507.-1721560101 uhci_dump_qh#13@0: called!
 1487337507.-1721547217 uhci_dump_qh#13@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487337507.-1721537768 uhci_dump_qh#14@0: called!
 1487337507.-1721527030 uhci_dump_qh#14@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487337507.-1721514575 uhci_dump_qh#15@0: called!
 1487337507.-1721503838 uhci_dump_qh#15@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487337507.-1721485799 uhci_device_ctrl_start#2@0: Enqueued QH:
 1487337507.-1721474632 uhci_dump_qh#16@0: called!
 1487337507.-1721465184 uhci_dump_qh#16@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337507.-1721455735 uhci_dump_td#36@0: called!
 1487337507.-1721444997 uhci_dump_td#36@0: TD(0xd24770) at 0x00d24770
 1487337507.-1721438555 uhci_dump_td#36@0:    link=0x00d24740 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487337507.-1721428247 uhci_dump_td#36@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721420087 uhci_dump_td#36@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.-1721410209 uhci_dump_td#36@0: ios     =0 ls      =1 spd     =0
 1487337507.-1721404625 uhci_dump_td#36@0: errcnt  =3 actlen  =1024 pid=2d
 1487337507.-1721394317 uhci_dump_td#36@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.-1721384010 uhci_dump_td#37@0: called!
 1487337507.-1721376279 uhci_dump_td#37@0: TD(0xd24740) at 0x00d24740
 1487337507.-1721370695 uhci_dump_td#37@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487337507.-1721361676 uhci_dump_td#37@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721353516 uhci_dump_td#37@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337507.-1721345355 uhci_dump_td#37@0: ios     =0 ls      =1 spd     =1
 1487337507.-1721338913 uhci_dump_td#37@0: errcnt  =3 actlen  =1024 pid=69
 1487337507.-1721330323 uhci_dump_td#37@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.-1721318727 uhci_dump_td#38@0: called!
 1487337507.-1721309708 uhci_dump_td#38@0: TD(0xd247a0) at 0x00d247a0
 1487337507.-1721303265 uhci_dump_td#38@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487337507.-1721293816 uhci_dump_td#38@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1721285656 uhci_dump_td#38@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337507.-1721277496 uhci_dump_td#38@0: ios     =0 ls      =1 spd     =0
 1487337507.-1721271053 uhci_dump_td#38@0: errcnt  =3 actlen  =1024 pid=e1
 1487337507.-1721262034 uhci_dump_td#38@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.-1721247431 uhci_device_ctrl_start#2@0: --- dump end ---
 1487337507.-1721191597 usbd_transfer#7@0: <- done transfer 0x3e08e00, err = 1
 1487337507.-1721162821 usbd_transfer#7@0: <- sleeping on xfer 0x3e08e00
 1487337507.-1707224099 uhci_intr#3@0: called!
 1487337507.-1707154521 uhci_intr1#3@0: called!
 1487337507.-1707138200 uhci_intr1#3@0: sc 0x3e32008
 1487337507.-1707108995 uhci_dumpregs#3@0: called!
 1487337507.-1707091815 uhci_dumpregs#3@0: cmd =0081  sts    =0001  intr   =000f  frnum =0579
 1487337507.-1707059603 uhci_dumpregs#3@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487337507.-1706991314 usb_schedsoftintr#3@0: called!
 1487337507.-1706973276 usb_schedsoftintr#3@0: polling=0
 1487337507.-1706937198 uhci_intr1#3@0: sc 0x3e32008 done
 1487337507.-1706809210 uhci_softintr#3@0: called!
 1487337507.-1706791601 uhci_softintr#3@0: sc 0x3e32008
 1487337507.-1706748222 uhci_check_intr#2@0: called!
 1487337507.-1706728036 uhci_check_intr#2@0: ux 0x3e08e00
 1487337507.-1706683369 uhci_check_intr#2@0: ux=0x3e08e00 done
 1487337507.-1706617227 uhci_idone#2@0: called!
 1487337507.-1706603054 uhci_idone#2@0: ux=0x3e08e00
 1487337507.-1706575996 uhci_idone#2@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x32c3748 ready
 1487337507.-1706558387 uhci_idone#2@0: --- dump start ---
 1487337507.-1706538201 uhci_dump_td#39@0: called!
 1487337507.-1706525745 uhci_dump_td#39@0: TD(0xd24770) at 0x00d24770
 1487337507.-1706508995 uhci_dump_td#39@0:    link=0x00d24740 status=0x1c000007 token=0x00e0002d buffer=0x00d5dec0
 1487337507.-1706485803 uhci_dump_td#39@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1706467764 uhci_dump_td#39@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.-1706455738 uhci_dump_td#39@0: ios     =0 ls      =1 spd     =0
 1487337507.-1706440276 uhci_dump_td#39@0: errcnt  =3 actlen  =8 pid=2d
 1487337507.-1706428680 uhci_dump_td#39@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337507.-1706412359 uhci_dump_td#40@0: called!
 1487337507.-1706404629 uhci_dump_td#40@0: TD(0xd24740) at 0x00d24740
 1487337507.-1706397327 uhci_dump_td#40@0:    link=0x00d247a0 status=0x1c000007 token=0x00e80069 buffer=0x00d5de80
 1487337507.-1706386590 uhci_dump_td#40@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1706378430 uhci_dump_td#40@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337507.-1706370269 uhci_dump_td#40@0: ios     =0 ls      =1 spd     =0
 1487337507.-1706359532 uhci_dump_td#40@0: errcnt  =3 actlen  =8 pid=69
 1487337507.-1706351801 uhci_dump_td#40@0: addr=0  endpt=0  D=1  maxlen=8,
 1487337507.-1706340634 uhci_dump_td#41@0: called!
 1487337507.-1706334192 uhci_dump_td#41@0: TD(0xd247a0) at 0x00d247a0
 1487337507.-1706323025 uhci_dump_td#41@0:    link=0x00000001 status=0x1d0007ff token=0xffe800e1 buffer=0x00000000
 1487337507.-1706314865 uhci_dump_td#41@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337507.-1706304557 uhci_dump_td#41@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487337507.-1706298544 uhci_dump_td#41@0: ios     =0 ls      =1 spd     =0
 1487337507.-1706289954 uhci_dump_td#41@0: errcnt  =3 actlen  =0 pid=e1
 1487337507.-1706281794 uhci_dump_td#41@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337507.-1706265473 uhci_idone#2@0: --- dump end ---
 1487337507.-1706235409 uhci_idone#2@0: actlen=8, status=0x0
 1487337507.-1706200620 uhci_idone#2@0: ux=0x3e08e00 done
 1487337507.-1706172274 uhci_softintr#3@0: ux 0x3e08e00
 1487337507.-1706137055 usb_transfer_complete#9@0: called!
 1487337507.-1706120735 usb_transfer_complete#9@0: pipe = 0x32c3748 xfer = 0x3e08e00 status = 0 actlen = 8
 1487337507.-1706088523 usb_transfer_complete#9@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.-1706064471 usb_transfer_complete#9@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487337507.-1706021952 uhci_device_ctrl_done#2@0: called!
 1487337507.-1705989310 uhci_remove_ls_ctrl#2@0: called!
 1487337507.-1705969554 uhci_remove_ls_ctrl#2@0: sqh 0xd22710
 1487337507.-1705933476 uhci_find_prev_qh#2@0: called!
 1487337507.-1705914579 uhci_find_prev_qh#2@0: pqh=0xd20740 sqh=0xd22710
 1487337507.-1705850584 uhci_device_ctrl_done#2@0: length=8
 1487337507.-1705815366 usb_transfer_complete#9@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337507.-1705790026 usb_transfer_complete#9@0: <- done xfer 0x3e08e00, wakeup
 1487337507.-1705637556 usbd_start_next#9@0: called!
 1487337507.-1705609210 usbd_start_next#9@0: pipe = 0x32c3748, xfer = 0x0
 1487337507.-1705334765 uhci_free_stds#2@0: called!
 1487337507.-1705318015 uhci_free_stds#2@0: ux=0x3e08e00
 1487337507.-1705218802 usbd_free_xfer#7@0: called!
 1487337507.-1705202481 usbd_free_xfer#7@0: 0x3e08e00
 1487337507.-1705164257 usb_freemem#4@0: called!
 1487337507.-1705123455 usb_freemem#4@0: frag=0xd5de80
 1487337507.-1705001909 usbd_reset_port#2@0: called!
 1487337507.-1704976569 usbd_do_request_flags#8@0: called!
 1487337507.-1704954235 usbd_alloc_xfer#8@0: called!
 1487337507.-1704895395 usbd_alloc_xfer#8@0: returns 0x3e08e00
 1487337507.-1704850298 usbd_transfer#8@0: called!
 1487337507.-1704834837 usbd_transfer#8@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337507.-1704809926 usbd_dump_queue#8@0: called!
 1487337507.-1704797900 usbd_dump_queue#8@0: pipe = 0x3e2d6c8
 1487337507.-1704767406 usb_insert_transfer#8@0: called!
 1487337507.-1704756240 usb_insert_transfer#8@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337507.-1704736912 usb_insert_transfer#8@0: <- done xfer 0x3e08e00, err 0
 1487337507.-1704705130 roothub_ctrl_start#6@0: called!
 1487337507.-1704684514 roothub_ctrl_start#6@0: type=0x23 request=0x3
 1487337507.-1704636841 uhci_roothub_ctrl#6@0: called!
 1487337507.-1704615366 uhci_roothub_ctrl#6@0: type=0x23 request=03
 1487337507.-1704562539 uhci_portreset#2@0: called!
 1487337507.-1594924911 uhci_poll_hub#40@0: called!
 1487337507.-1594854045 usb_transfer_complete#10@0: called!
 1487337507.-1594843308 usb_transfer_complete#10@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487337507.-1594825698 usb_transfer_complete#10@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487337507.-1594805942 usb_transfer_complete#10@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487337507.-1594785756 usb_transfer_complete#10@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487337507.-1594744525 usbd_start_next#10@0: called!
 1487337507.-1594726915 usbd_start_next#10@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487337507.-1594696851 uhci_root_intr_start#3@0: called!
 1487337507.-1594680530 uhci_root_intr_start#3@0: xfer=0x3e08ee0 len=1 flags=132
 1487337507.-607235796 uhci_portreset#2@0: uhci port 1 reset, status0 = 0x038a
 1487337507.-606775381 uhci_portreset#2@0: uhci port 1 reset, status1 = 0x01ab
 1487337507.-521595586 uhci_poll_hub#41@0: called!
 1487337507.-521540181 usb_transfer_complete#11@0: called!
 1487337507.-521529444 usb_transfer_complete#11@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487337507.-521512694 usb_transfer_complete#11@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487337507.-521497662 usb_transfer_complete#11@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487337507.-521477475 usb_transfer_complete#11@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487337507.-521443546 usbd_start_next#11@0: called!
 1487337507.-521428084 usbd_start_next#11@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487337507.-521399737 uhci_root_intr_start#4@0: called!
 1487337507.-521384705 uhci_root_intr_start#4@0: xfer=0x3e08ee0 len=1 flags=132
 1487337507.-349658902 uhci_portreset#2@0: uhci port 1 iteration 9, status = 0x01af
 1487337507.-92008995 uhci_portreset#2@0: uhci port 1 iteration 8, status = 0x01a5
 1487337507.-91991816 uhci_portreset#2@0: uhci port 1 reset, status2 = 0x01a5
 1487337507.-91954879 roothub_ctrl_start#6@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337507.-91935982 roothub_ctrl_start#6@0: xfer 0x3e08e00 err 0
 1487337507.-91910212 usb_transfer_complete#12@0: called!
 1487337507.-91899904 usb_transfer_complete#12@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337507.-91885302 usb_transfer_complete#12@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337507.-91866833 usb_transfer_complete#12@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337507.-91850513 usb_transfer_complete#12@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337507.-91838058 usb_transfer_complete#12@0: <- done xfer 0x3e08e00, wakeup
 1487337507.-91820448 usbd_start_next#12@0: called!
 1487337507.-91806705 usbd_start_next#12@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337507.-91776640 usbd_transfer#8@0: <- done transfer 0x3e08e00, err = 0
 1487337507.-91759031 usbd_transfer#8@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337507.-91712646 usbd_free_xfer#8@0: called!
 1487337507.-91698043 usbd_free_xfer#8@0: 0x3e08e00
 1487337507.-91605703 usbd_reset_port#2@0: port 1 reset done, error=0
 1487337508.165741413 usbd_get_port_status#3@0: called!
 1487337508.165756015 usbd_get_port_status#3@0: dev 0x3e27298 port 1
 1487337508.165776202 usbd_do_request_flags#9@0: called!
 1487337508.165795529 usbd_alloc_xfer#9@0: called!
 1487337508.165868972 usbd_alloc_xfer#9@0: returns 0x3e08e00
 1487337508.165901184 usb_allocmem_flags#6@0: called!
 1487337508.165938979 usb_allocmem_flags#6@0: use frag=0xd5de80 size=4
 1487337508.165983646 usbd_transfer#9@0: called!
 1487337508.165994813 usbd_transfer#9@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337508.166013711 usbd_dump_queue#9@0: called!
 1487337508.166025307 usbd_dump_queue#9@0: pipe = 0x3e2d6c8
 1487337508.166051076 usb_insert_transfer#9@0: called!
 1487337508.166062673 usb_insert_transfer#9@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337508.166080282 usb_insert_transfer#9@0: <- done xfer 0x3e08e00, err 0
 1487337508.166102186 roothub_ctrl_start#7@0: called!
 1487337508.166113353 roothub_ctrl_start#7@0: type=0xa3 request= 0
 1487337508.166143846 uhci_roothub_ctrl#7@0: called!
 1487337508.166153725 uhci_roothub_ctrl#7@0: type=0xa3 request=00
 1487337508.166194956 uhci_roothub_ctrl#7@0: returning 4
 1487337508.166210418 roothub_ctrl_start#7@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487337508.166222443 roothub_ctrl_start#7@0: xfer 0x3e08e00 err 0
 1487337508.166237476 usb_transfer_complete#13@0: called!
 1487337508.166249072 usb_transfer_complete#13@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487337508.166264963 usb_transfer_complete#13@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.166278707 usb_transfer_complete#13@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337508.166298893 usb_transfer_complete#13@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337508.166312637 usb_transfer_complete#13@0: <- done xfer 0x3e08e00, wakeup
 1487337508.166334111 usbd_start_next#13@0: called!
 1487337508.166347855 usbd_start_next#13@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337508.166364605 usbd_transfer#9@0: <- done transfer 0x3e08e00, err = 0
 1487337508.166376201 usbd_transfer#9@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337508.166392522 usbd_free_xfer#9@0: called!
 1487337508.166403259 usbd_free_xfer#9@0: 0x3e08e00
 1487337508.166429888 usb_freemem#5@0: called!
 1487337508.166452222 usb_freemem#5@0: frag=0xd5de80
 1487337508.166543703 usbd_clear_port_feature#3@0: called!
 1487337508.166560024 usbd_clear_port_feature#3@0: dev 0x3e27298 port 1 sel 20
 1487337508.166577633 usbd_do_request_flags#10@0: called!
 1487337508.166590088 usbd_alloc_xfer#10@0: called!
 1487337508.166618005 usbd_alloc_xfer#10@0: returns 0x3e08e00
 1487337508.166635185 usbd_transfer#10@0: called!
 1487337508.166641627 usbd_transfer#10@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337508.166654942 usbd_dump_queue#10@0: called!
 1487337508.166666108 usbd_dump_queue#10@0: pipe = 0x3e2d6c8
 1487337508.166678993 usb_insert_transfer#10@0: called!
 1487337508.166684576 usb_insert_transfer#10@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337508.166695743 usb_insert_transfer#10@0: <- done xfer 0x3e08e00, err 0
 1487337508.166709917 roothub_ctrl_start#8@0: called!
 1487337508.166721942 roothub_ctrl_start#8@0: type=0x23 request=0x1
 1487337508.166734827 uhci_roothub_ctrl#8@0: called!
 1487337508.166743417 uhci_roothub_ctrl#8@0: type=0x23 request=01
 1487337508.166762744 uhci_roothub_ctrl#8@0: UR_CLEAR_PORT_FEATURE port=1 feature=20
 1487337508.166786366 uhci_roothub_ctrl#8@0: returning 0
 1487337508.166794956 roothub_ctrl_start#8@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337508.166803546 roothub_ctrl_start#8@0: xfer 0x3e08e00 err 0
 1487337508.166818578 usb_transfer_complete#14@0: called!
 1487337508.166830174 usb_transfer_complete#14@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337508.166841770 usb_transfer_complete#14@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.166851649 usb_transfer_complete#14@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337508.166863675 usb_transfer_complete#14@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337508.166873553 usb_transfer_complete#14@0: <- done xfer 0x3e08e00, wakeup
 1487337508.166887726 usbd_start_next#14@0: called!
 1487337508.166901470 usbd_start_next#14@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337508.166919079 usbd_transfer#10@0: <- done transfer 0x3e08e00, err = 0
 1487337508.166928098 usbd_transfer#10@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337508.166939695 usbd_free_xfer#10@0: called!
 1487337508.166952150 usbd_free_xfer#10@0: 0x3e08e00
 1487337508.552291219 uhci_poll_hub#42@0: called!
 1487337508.1282450684 usbd_new_device#1@0: adding unit addr=2, rev=200, class=0, subclass=0
 1487337508.1282469582 usbd_new_device#1@0: protocol=0, maxpacket=8, len=18, speed=1
 1487337508.1282522839 usbd_ar_pipe#1@0: called!
 1487337508.1282542596 usbd_ar_pipe#1@0: pipe = 0x32c3748
 1487337508.1282562782 usbd_dump_queue#11@0: called!
 1487337508.1282571372 usbd_dump_queue#11@0: pipe = 0x32c3748
 1487337508.1282652546 usb_rem_task#1@0: called!
 1487337508.1282741450 usbd_setup_pipe_flags#2@0: called!
 1487337508.1282798143 usbd_setup_pipe_flags#2@0: dev=0x375d7c0 addr=0 iface=0x0 ep=0x375d7e4 pipe=0xfdc04745
 1487337508.1282826490 uhci_open#2@0: called!
 1487337508.1282844528 uhci_open#2@0: pipe=0x32c3748, addr=0, endpt=0 (1)
 1487337508.1282879747 uhci_alloc_sqh#2@0: called!
 1487337508.1282909811 uhci_alloc_std#12@0: called!
 1487337508.1282925702 uhci_alloc_std#13@0: called!
 1487337508.1282948036 usb_allocmem_flags#7@0: called!
 1487337508.1282977241 usb_allocmem_flags#7@0: use frag=0xd5de80 size=8
 1487337508.1283002581 usbd_setup_pipe_flags#2@0: pipe=0x32c3748
 1487337508.1283028351 usbd_new_device#1@0: setting device address=2
 1487337508.1283056268 usbd_set_address#1@0: called!
 1487337508.1283073018 usbd_set_address#1@0: dev 0x375d7c0 addr 2
 1487337508.1283095351 usbd_do_request_flags#11@0: called!
 1487337508.1283107807 usbd_alloc_xfer#11@0: called!
 1487337508.1283156769 usbd_alloc_xfer#11@0: returns 0x3e08e00
 1487337508.1283178243 uhci_device_ctrl_init#3@0: called!
 1487337508.1283188981 uhci_device_ctrl_init#3@0: xfer=0x3e08e00 len=0, addr=0, endpt=0
 1487337508.1283216039 usbd_transfer#11@0: called!
 1487337508.1283226346 usbd_transfer#11@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x32c3748, running = 0
 1487337508.1283237943 usbd_dump_queue#12@0: called!
 1487337508.1283246103 usbd_dump_queue#12@0: pipe = 0x32c3748
 1487337508.1283264142 usb_insert_transfer#11@0: called!
 1487337508.1283274879 usb_insert_transfer#11@0: xfer = 0x3e08e00 pipe = 0x32c3748 running = 0 timeout = 5000
 1487337508.1283291200 usb_insert_transfer#11@0: <- done xfer 0x3e08e00, err 0
 1487337508.1283318258 uhci_device_ctrl_start#3@0: called!
 1487337508.1283330283 uhci_device_ctrl_start#3@0: type=0x00, request=0x05, wValue=0x0002, wIndex=0x0000
 1487337508.1283347463 uhci_device_ctrl_start#3@0: len=0, addr=0, endpt=0
 1487337508.1283406733 uhci_device_ctrl_start#3@0: --- dump start ---
 1487337508.1283421336 uhci_device_ctrl_start#3@0: before transfer
 1487337508.1283441092 uhci_dump_td#42@0: called!
 1487337508.1283453977 uhci_dump_td#42@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1283469439 uhci_dump_td#42@0:    link=0x00d24770 status=0x1c8003ff token=0x00e0002d buffer=0x00d5de80
 1487337508.1283487048 uhci_dump_td#42@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1283502939 uhci_dump_td#42@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1283520978 uhci_dump_td#42@0: ios     =0 ls      =1 spd     =0
 1487337508.1283533862 uhci_dump_td#42@0: errcnt  =3 actlen  =1024 pid=2d
 1487337508.1283549754 uhci_dump_td#42@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337508.1283563497 uhci_dump_td#43@0: called!
 1487337508.1283572946 uhci_dump_td#43@0: TD(0xd24770) at 0x00d24770
 1487337508.1283581107 uhci_dump_td#43@0:    link=0x00000001 status=0x1d8003ff token=0xffe80069 buffer=0x00000000
 1487337508.1283589267 uhci_dump_td#43@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1283595709 uhci_dump_td#43@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337508.1283604729 uhci_dump_td#43@0: ios     =0 ls      =1 spd     =0
 1487337508.1283612889 uhci_dump_td#43@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1283621049 uhci_dump_td#43@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337508.1283633934 uhci_device_ctrl_start#3@0: --- dump end ---
 1487337508.1283665287 uhci_add_ls_ctrl#3@0: called!
 1487337508.1283676454 uhci_add_ls_ctrl#3@0: sqh 0xd22710
 1487337508.1283706089 uhci_device_ctrl_start#3@0: --- dump start ---
 1487337508.1283722839 uhci_device_ctrl_start#3@0: follow from [0]
 1487337508.1283741307 uhci_dump_td#44@0: called!
 1487337508.1283754192 uhci_dump_td#44@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487337508.1283762352 uhci_dump_td#44@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487337508.1283768365 uhci_dump_td#44@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1283777814 uhci_dump_td#44@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1283785974 uhci_dump_td#44@0: ios     =1 ls      =0 spd     =0
 1487337508.1283794134 uhci_dump_td#44@0: errcnt  =0 actlen  =1 pid=00
 1487337508.1283800577 uhci_dump_td#44@0: addr=0  endpt=0  D=0  maxlen=1,
 1487337508.1283822051 uhci_dump_qh#17@0: called!
 1487337508.1283835795 uhci_dump_qh#17@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337508.1283851257 uhci_dump_qh#18@0: called!
 1487337508.1283858558 uhci_dump_qh#18@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337508.1283872302 uhci_dump_qh#19@0: called!
 1487337508.1283880462 uhci_dump_qh#19@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487337508.1283889911 uhci_dump_qh#20@0: called!
 1487337508.1283895924 uhci_dump_qh#20@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d247a0
 1487337508.1283906232 uhci_dump_qh#21@0: called!
 1487337508.1283916110 uhci_dump_qh#21@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487337508.1283925559 uhci_dump_qh#22@0: called!
 1487337508.1283934149 uhci_dump_qh#22@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487337508.1283945745 uhci_dump_qh#23@0: called!
 1487337508.1283953905 uhci_dump_qh#23@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487337508.1283967649 uhci_device_ctrl_start#3@0: Enqueued QH:
 1487337508.1283976239 uhci_dump_qh#24@0: called!
 1487337508.1283985688 uhci_dump_qh#24@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d247a0
 1487337508.1283995566 uhci_dump_td#45@0: called!
 1487337508.1284006303 uhci_dump_td#45@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1284011887 uhci_dump_td#45@0:    link=0x00d24770 status=0x1c8003ff token=0x00e0002d buffer=0x00d5de80
 1487337508.1284021336 uhci_dump_td#45@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1284029066 uhci_dump_td#45@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1284037227 uhci_dump_td#45@0: ios     =0 ls      =1 spd     =0
 1487337508.1284044099 uhci_dump_td#45@0: errcnt  =3 actlen  =1024 pid=2d
 1487337508.1284053547 uhci_dump_td#45@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337508.1284064285 uhci_dump_td#46@0: called!
 1487337508.1284072016 uhci_dump_td#46@0: TD(0xd24770) at 0x00d24770
 1487337508.1284079317 uhci_dump_td#46@0:    link=0x00000001 status=0x1d8003ff token=0xffe80069 buffer=0x00000000
 1487337508.1284087907 uhci_dump_td#46@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1284095638 uhci_dump_td#46@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337508.1284103798 uhci_dump_td#46@0: ios     =0 ls      =1 spd     =0
 1487337508.1284110670 uhci_dump_td#46@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1284118401 uhci_dump_td#46@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337508.1284133003 uhci_device_ctrl_start#3@0: --- dump end ---
 1487337508.1284178529 usbd_transfer#11@0: <- done transfer 0x3e08e00, err = 1
 1487337508.1284200863 usbd_transfer#11@0: <- sleeping on xfer 0x3e08e00
 1487337508.1294943738 uhci_intr#4@0: called!
 1487337508.1294977239 uhci_intr1#4@0: called!
 1487337508.1294989694 uhci_intr1#4@0: sc 0x3e32008
 1487337508.1295005585 uhci_dumpregs#4@0: called!
 1487337508.1295016752 uhci_dumpregs#4@0: cmd =0081  sts    =0001  intr   =000f  frnum =0034
 1487337508.1295037367 uhci_dumpregs#4@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487337508.1295080746 usb_schedsoftintr#4@0: called!
 1487337508.1295092772 usb_schedsoftintr#4@0: polling=0
 1487337508.1295128420 uhci_intr1#4@0: sc 0x3e32008 done
 1487337508.1295256838 uhci_softintr#4@0: called!
 1487337508.1295273588 uhci_softintr#4@0: sc 0x3e32008
 1487337508.1295297639 uhci_check_intr#3@0: called!
 1487337508.1295308806 uhci_check_intr#3@0: ux 0x3e08e00
 1487337508.1295332858 uhci_check_intr#3@0: ux=0x3e08e00 done
 1487337508.1295374089 uhci_idone#3@0: called!
 1487337508.1295383967 uhci_idone#3@0: ux=0x3e08e00
 1487337508.1295398570 uhci_idone#3@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x32c3748 ready
 1487337508.1295409307 uhci_idone#3@0: --- dump start ---
 1487337508.1295425628 uhci_dump_td#47@0: called!
 1487337508.1295434647 uhci_dump_td#47@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1295447532 uhci_dump_td#47@0:    link=0x00d24770 status=0x1c000007 token=0x00e0002d buffer=0x00d5de80
 1487337508.1295460846 uhci_dump_td#47@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1295479314 uhci_dump_td#47@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1295488763 uhci_dump_td#47@0: ios     =0 ls      =1 spd     =0
 1487337508.1295498212 uhci_dump_td#47@0: errcnt  =3 actlen  =8 pid=2d
 1487337508.1295510667 uhci_dump_td#47@0: addr=0  endpt=0  D=0  maxlen=8,
 1487337508.1295525699 uhci_dump_td#48@0: called!
 1487337508.1295532142 uhci_dump_td#48@0: TD(0xd24770) at 0x00d24770
 1487337508.1295541161 uhci_dump_td#48@0:    link=0x00000001 status=0x1d0007ff token=0xffe80069 buffer=0x00000000
 1487337508.1295549321 uhci_dump_td#48@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1295557482 uhci_dump_td#48@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487337508.1295563924 uhci_dump_td#48@0: ios     =0 ls      =1 spd     =0
 1487337508.1295573373 uhci_dump_td#48@0: errcnt  =3 actlen  =0 pid=69
 1487337508.1295581533 uhci_dump_td#48@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487337508.1295593130 uhci_idone#3@0: --- dump end ---
 1487337508.1295607303 uhci_idone#3@0: actlen=0, status=0x0
 1487337508.1295625342 uhci_idone#3@0: ux=0x3e08e00 done
 1487337508.1295640803 uhci_softintr#4@0: ux 0x3e08e00
 1487337508.1295657124 usb_transfer_complete#15@0: called!
 1487337508.1295667002 usb_transfer_complete#15@0: pipe = 0x32c3748 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337508.1295683752 usb_transfer_complete#15@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.1295697496 usb_transfer_complete#15@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487337508.1295731426 uhci_device_ctrl_done#3@0: called!
 1487337508.1295763638 uhci_remove_ls_ctrl#3@0: called!
 1487337508.1295781247 uhci_remove_ls_ctrl#3@0: sqh 0xd22710
 1487337508.1295804869 uhci_find_prev_qh#3@0: called!
 1487337508.1295823337 uhci_find_prev_qh#3@0: pqh=0xd20740 sqh=0xd22710
 1487337508.1295877883 uhci_device_ctrl_done#3@0: length=0
 1487337508.1295892915 usb_transfer_complete#15@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337508.1295905800 usb_transfer_complete#15@0: <- done xfer 0x3e08e00, wakeup
 1487337508.1296007160 usbd_start_next#15@0: called!
 1487337508.1296020044 usbd_start_next#15@0: pipe = 0x32c3748, xfer = 0x0
 1487337508.1296204726 uhci_free_stds#3@0: called!
 1487337508.1296218899 uhci_free_stds#3@0: ux=0x3e08e00
 1487337508.1296246816 usbd_free_xfer#11@0: called!
 1487337508.1296255835 usbd_free_xfer#11@0: 0x3e08e00
 1487337508.1368515662 usbd_ar_pipe#2@0: called!
 1487337508.1368531123 usbd_ar_pipe#2@0: pipe = 0x32c3748
 1487337508.1368548733 usbd_dump_queue#13@0: called!
 1487337508.1368557752 usbd_dump_queue#13@0: pipe = 0x32c3748
 1487337508.1368607573 usb_rem_task#2@0: called!
 1487337508.1368692183 usbd_setup_pipe_flags#3@0: called!
 1487337508.1368739856 usbd_setup_pipe_flags#3@0: dev=0x375d7c0 addr=2 iface=0x0 ep=0x375d7e4 pipe=0xfdc045b9
 1487337508.1368762619 uhci_open#3@0: called!
 1487337508.1368778940 uhci_open#3@0: pipe=0x32c3748, addr=2, endpt=0 (1)
 1487337508.1368808146 uhci_alloc_sqh#3@0: called!
 1487337508.1368833486 uhci_alloc_std#14@0: called!
 1487337508.1368845082 uhci_alloc_std#15@0: called!
 1487337508.1368871710 usb_allocmem_flags#8@0: called!
 1487337508.1368907788 usb_allocmem_flags#8@0: use frag=0xd5de40 size=8
 1487337508.1368931410 usbd_setup_pipe_flags#3@0: pipe=0x32c3748
 1487337508.1368964481 usbd_reload_device_desc#1@0: called!
 1487337508.1368994115 usbd_get_device_desc#1@0: called!
 1487337508.1369029763 usbd_get_desc#1@0: called!
 1487337508.1369046513 usbd_get_desc#1@0: type=1, index=0, len=18
 1487337508.1369070135 usbd_do_request_flags#12@0: called!
 1487337508.1369085597 usbd_alloc_xfer#12@0: called!
 1487337508.1369134559 usbd_alloc_xfer#12@0: returns 0x3e08e00
 1487337508.1369156893 usb_allocmem_flags#9@0: called!
 1487337508.1369170207 usb_allocmem_flags#9@0: use frag=0xd5de00 size=18
 1487337508.1369190823 uhci_device_ctrl_init#4@0: called!
 1487337508.1369201560 uhci_device_ctrl_init#4@0: xfer=0x3e08e00 len=18, addr=2, endpt=0
 1487337508.1369228618 uhci_alloc_std_chain#3@0: called!
 1487337508.1369237208 uhci_alloc_std_chain#3@0: xfer=0x3e08e00 pipe=0x32c3748
 1487337508.1369250092 uhci_alloc_std_chain#3@0: maxp=8 ntd=3
 1487337508.1369305926 uhci_alloc_std#16@0: called!
 1487337508.1369321388 uhci_alloc_std#17@0: called!
 1487337508.1369335132 uhci_alloc_std#18@0: called!
 1487337508.1369376363 usbd_transfer#12@0: called!
 1487337508.1369387530 usbd_transfer#12@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x32c3748, running = 0
 1487337508.1369397838 usbd_dump_queue#14@0: called!
 1487337508.1369403421 usbd_dump_queue#14@0: pipe = 0x32c3748
 1487337508.1369426184 usb_insert_transfer#12@0: called!
 1487337508.1369437780 usb_insert_transfer#12@0: xfer = 0x3e08e00 pipe = 0x32c3748 running = 0 timeout = 5000
 1487337508.1369452383 usb_insert_transfer#12@0: <- done xfer 0x3e08e00, err 0
 1487337508.1369471281 uhci_device_ctrl_start#4@0: called!
 1487337508.1369485454 uhci_device_ctrl_start#4@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487337508.1369497050 uhci_device_ctrl_start#4@0: len=18, addr=2, endpt=0
 1487337508.1369530121 uhci_reset_std_chain#3@0: called!
 1487337508.1369543006 uhci_reset_std_chain#3@0: xfer=0x3e08e00 len 18 isread 128 toggle 1
 1487337508.1369617308 uhci_device_ctrl_start#4@0: --- dump start ---
 1487337508.1369634488 uhci_device_ctrl_start#4@0: before transfer
 1487337508.1369657251 uhci_dump_td#49@0: called!
 1487337508.1369668847 uhci_dump_td#49@0: TD(0xd24770) at 0x00d24770
 1487337508.1369683879 uhci_dump_td#49@0:    link=0x00d246e0 status=0x1c8003ff token=0x00e0022d buffer=0x00d5de40
 1487337508.1369701918 uhci_dump_td#49@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1369720815 uhci_dump_td#49@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1369731123 uhci_dump_td#49@0: ios     =0 ls      =1 spd     =0
 1487337508.1369742719 uhci_dump_td#49@0: errcnt  =3 actlen  =1024 pid=2d
 1487337508.1369760758 uhci_dump_td#49@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1369777079 uhci_dump_td#50@0: called!
 1487337508.1369784810 uhci_dump_td#50@0: TD(0xd246e0) at 0x00d246e0
 1487337508.1369793829 uhci_dump_td#50@0:    link=0x00d24714 status=0x3c8003ff token=0x00e80269 buffer=0x00d5de00
 1487337508.1369801989 uhci_dump_td#50@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1369810150 uhci_dump_td#50@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1369817021 uhci_dump_td#50@0: ios     =0 ls      =1 spd     =1
 1487337508.1369827329 uhci_dump_td#50@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1369835490 uhci_dump_td#50@0: addr=2  endpt=0  D=1  maxlen=8,
 1487337508.1369845797 uhci_dump_td#51@0: called!
 1487337508.1369853099 uhci_dump_td#51@0: TD(0xd24710) at 0x00d24710
 1487337508.1369862548 uhci_dump_td#51@0:    link=0x00d24744 status=0x3c8003ff token=0x00e00269 buffer=0x00d5de08
 1487337508.1369870708 uhci_dump_td#51@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1369878868 uhci_dump_td#51@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1369885311 uhci_dump_td#51@0: ios     =0 ls      =1 spd     =1
 1487337508.1369895618 uhci_dump_td#51@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1369903349 uhci_dump_td#51@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1369913657 uhci_dump_td#52@0: called!
 1487337508.1369921388 uhci_dump_td#52@0: TD(0xd24740) at 0x00d24740
 1487337508.1369930407 uhci_dump_td#52@0:    link=0x00d247a0 status=0x3c8003ff token=0x00280269 buffer=0x00d5de10
 1487337508.1369938568 uhci_dump_td#52@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1369946728 uhci_dump_td#52@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1369952741 uhci_dump_td#52@0: ios     =0 ls      =1 spd     =1
 1487337508.1369963049 uhci_dump_td#52@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1369971638 uhci_dump_td#52@0: addr=2  endpt=0  D=1  maxlen=2,
 1487337508.1369981946 uhci_dump_td#53@0: called!
 1487337508.1369989677 uhci_dump_td#53@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1369997837 uhci_dump_td#53@0:    link=0x00000001 status=0x1d8003ff token=0xffe802e1 buffer=0x00000000
 1487337508.1370005998 uhci_dump_td#53@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370014158 uhci_dump_td#53@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337508.1370020171 uhci_dump_td#53@0: ios     =0 ls      =1 spd     =0
 1487337508.1370028761 uhci_dump_td#53@0: errcnt  =3 actlen  =1024 pid=e1
 1487337508.1370037780 uhci_dump_td#53@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487337508.1370053242 uhci_device_ctrl_start#4@0: --- dump end ---
 1487337508.1370075146 uhci_add_ls_ctrl#4@0: called!
 1487337508.1370086742 uhci_add_ls_ctrl#4@0: sqh 0xd22710
 1487337508.1370115089 uhci_device_ctrl_start#4@0: --- dump start ---
 1487337508.1370128403 uhci_device_ctrl_start#4@0: follow from [0]
 1487337508.1370139999 uhci_dump_td#54@0: called!
 1487337508.1370152884 uhci_dump_td#54@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487337508.1370161044 uhci_dump_td#54@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487337508.1370169634 uhci_dump_td#54@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370176077 uhci_dump_td#54@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1370186384 uhci_dump_td#54@0: ios     =1 ls      =0 spd     =0
 1487337508.1370194974 uhci_dump_td#54@0: errcnt  =0 actlen  =1 pid=00
 1487337508.1370203135 uhci_dump_td#54@0: addr=0  endpt=0  D=0  maxlen=1,
 1487337508.1370217308 uhci_dump_qh#25@0: called!
 1487337508.1370234487 uhci_dump_qh#25@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337508.1370253815 uhci_dump_qh#26@0: called!
 1487337508.1370262834 uhci_dump_qh#26@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487337508.1370271424 uhci_dump_qh#27@0: called!
 1487337508.1370279584 uhci_dump_qh#27@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487337508.1370289033 uhci_dump_qh#28@0: called!
 1487337508.1370297193 uhci_dump_qh#28@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337508.1370304924 uhci_dump_qh#29@0: called!
 1487337508.1370313943 uhci_dump_qh#29@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487337508.1370323392 uhci_dump_qh#30@0: called!
 1487337508.1370334988 uhci_dump_qh#30@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487337508.1370342290 uhci_dump_qh#31@0: called!
 1487337508.1370351739 uhci_dump_qh#31@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487337508.1370362905 uhci_device_ctrl_start#4@0: Enqueued QH:
 1487337508.1370373213 uhci_dump_qh#32@0: called!
 1487337508.1370379656 uhci_dump_qh#32@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487337508.1370390822 uhci_dump_td#55@0: called!
 1487337508.1370398983 uhci_dump_td#55@0: TD(0xd24770) at 0x00d24770
 1487337508.1370407143 uhci_dump_td#55@0:    link=0x00d246e0 status=0x1c8003ff token=0x00e0022d buffer=0x00d5de40
 1487337508.1370413156 uhci_dump_td#55@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370422605 uhci_dump_td#55@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1370430765 uhci_dump_td#55@0: ios     =0 ls      =1 spd     =0
 1487337508.1370439784 uhci_dump_td#55@0: errcnt  =3 actlen  =1024 pid=2d
 1487337508.1370447086 uhci_dump_td#55@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1370457823 uhci_dump_td#56@0: called!
 1487337508.1370466413 uhci_dump_td#56@0: TD(0xd246e0) at 0x00d246e0
 1487337508.1370474573 uhci_dump_td#56@0:    link=0x00d24714 status=0x3c8003ff token=0x00e80269 buffer=0x00d5de00
 1487337508.1370481016 uhci_dump_td#56@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370490464 uhci_dump_td#56@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1370498625 uhci_dump_td#56@0: ios     =0 ls      =1 spd     =1
 1487337508.1370507644 uhci_dump_td#56@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1370513657 uhci_dump_td#56@0: addr=2  endpt=0  D=1  maxlen=8,
 1487337508.1370523535 uhci_dump_td#57@0: called!
 1487337508.1370531696 uhci_dump_td#57@0: TD(0xd24710) at 0x00d24710
 1487337508.1370539856 uhci_dump_td#57@0:    link=0x00d24744 status=0x3c8003ff token=0x00e00269 buffer=0x00d5de08
 1487337508.1370545869 uhci_dump_td#57@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370554888 uhci_dump_td#57@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1370563049 uhci_dump_td#57@0: ios     =0 ls      =1 spd     =1
 1487337508.1370572068 uhci_dump_td#57@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1370578940 uhci_dump_td#57@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1370589677 uhci_dump_td#58@0: called!
 1487337508.1370597837 uhci_dump_td#58@0: TD(0xd24740) at 0x00d24740
 1487337508.1370606427 uhci_dump_td#58@0:    link=0x00d247a0 status=0x3c8003ff token=0x00280269 buffer=0x00d5de10
 1487337508.1370612440 uhci_dump_td#58@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370621459 uhci_dump_td#58@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1370629620 uhci_dump_td#58@0: ios     =0 ls      =1 spd     =1
 1487337508.1370637780 uhci_dump_td#58@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1370644222 uhci_dump_td#58@0: addr=2  endpt=0  D=1  maxlen=2,
 1487337508.1370655819 uhci_dump_td#59@0: called!
 1487337508.1370665697 uhci_dump_td#59@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1370673857 uhci_dump_td#59@0:    link=0x00000001 status=0x1d8003ff token=0xffe802e1 buffer=0x00000000
 1487337508.1370680300 uhci_dump_td#59@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1370688890 uhci_dump_td#59@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487337508.1370697050 uhci_dump_td#59@0: ios     =0 ls      =1 spd     =0
 1487337508.1370705210 uhci_dump_td#59@0: errcnt  =3 actlen  =1024 pid=e1
 1487337508.1370711653 uhci_dump_td#59@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487337508.1370724967 uhci_device_ctrl_start#4@0: --- dump end ---
 1487337508.1370774358 usbd_transfer#12@0: <- done transfer 0x3e08e00, err = 1
 1487337508.1370792827 usbd_transfer#12@0: <- sleeping on xfer 0x3e08e00
 1487337508.1385147727 uhci_intr#5@0: called!
 1487337508.1385179080 uhci_intr1#5@0: called!
 1487337508.1385189817 uhci_intr1#5@0: sc 0x3e32008
 1487337508.1385207856 uhci_dumpregs#5@0: called!
 1487337508.1385216445 uhci_dumpregs#5@0: cmd =0081  sts    =0001  intr   =000f  frnum =0049
 1487337508.1385236632 uhci_dumpregs#5@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487337508.1385279151 usb_schedsoftintr#5@0: called!
 1487337508.1385292895 usb_schedsoftintr#5@0: polling=0
 1487337508.1385325107 uhci_intr1#5@0: sc 0x3e32008 done
 1487337508.1385435057 uhci_softintr#5@0: called!
 1487337508.1385450948 uhci_softintr#5@0: sc 0x3e32008
 1487337508.1385477576 uhci_check_intr#4@0: called!
 1487337508.1385487025 uhci_check_intr#4@0: ux 0x3e08e00
 1487337508.1385510218 uhci_check_intr#4@0: ux=0x3e08e00 done
 1487337508.1385547154 uhci_idone#4@0: called!
 1487337508.1385557891 uhci_idone#4@0: ux=0x3e08e00
 1487337508.1385574212 uhci_idone#4@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x32c3748 ready
 1487337508.1385586238 uhci_idone#4@0: --- dump start ---
 1487337508.1385602129 uhci_dump_td#60@0: called!
 1487337508.1385612866 uhci_dump_td#60@0: TD(0xd24770) at 0x00d24770
 1487337508.1385621886 uhci_dump_td#60@0:    link=0x00d246e0 status=0x1c000007 token=0x00e0022d buffer=0x00d5de40
 1487337508.1385634770 uhci_dump_td#60@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1385651950 uhci_dump_td#60@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1385663546 uhci_dump_td#60@0: ios     =0 ls      =1 spd     =0
 1487337508.1385669989 uhci_dump_td#60@0: errcnt  =3 actlen  =8 pid=2d
 1487337508.1385682444 uhci_dump_td#60@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1385698335 uhci_dump_td#61@0: called!
 1487337508.1385707784 uhci_dump_td#61@0: TD(0xd246e0) at 0x00d246e0
 1487337508.1385715085 uhci_dump_td#61@0:    link=0x00d24714 status=0x1c000007 token=0x00e80269 buffer=0x00d5de00
 1487337508.1385725393 uhci_dump_td#61@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1385734842 uhci_dump_td#61@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1385742573 uhci_dump_td#61@0: ios     =0 ls      =1 spd     =0
 1487337508.1385749015 uhci_dump_td#61@0: errcnt  =3 actlen  =8 pid=69
 1487337508.1385757605 uhci_dump_td#61@0: addr=2  endpt=0  D=1  maxlen=8,
 1487337508.1385767913 uhci_dump_td#62@0: called!
 1487337508.1385776932 uhci_dump_td#62@0: TD(0xd24710) at 0x00d24710
 1487337508.1385783804 uhci_dump_td#62@0:    link=0x00d24744 status=0x1c000007 token=0x00e00269 buffer=0x00d5de08
 1487337508.1385794112 uhci_dump_td#62@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1385802702 uhci_dump_td#62@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487337508.1385810862 uhci_dump_td#62@0: ios     =0 ls      =1 spd     =0
 1487337508.1385816875 uhci_dump_td#62@0: errcnt  =3 actlen  =8 pid=69
 1487337508.1385825894 uhci_dump_td#62@0: addr=2  endpt=0  D=0  maxlen=8,
 1487337508.1385836631 uhci_dump_td#63@0: called!
 1487337508.1385845221 uhci_dump_td#63@0: TD(0xd24740) at 0x00d24740
 1487337508.1385851664 uhci_dump_td#63@0:    link=0x00d247a0 status=0x3c8003ff token=0x00280269 buffer=0x00d5de10
 1487337508.1385861971 uhci_dump_td#63@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1385870561 uhci_dump_td#63@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487337508.1385878722 uhci_dump_td#63@0: ios     =0 ls      =1 spd     =1
 1487337508.1385884734 uhci_dump_td#63@0: errcnt  =3 actlen  =1024 pid=69
 1487337508.1385893754 uhci_dump_td#63@0: addr=2  endpt=0  D=1  maxlen=2,
 1487337508.1385904491 uhci_dump_td#64@0: called!
 1487337508.1385912651 uhci_dump_td#64@0: TD(0xd247a0) at 0x00d247a0
 1487337508.1385918664 uhci_dump_td#64@0:    link=0x00000001 status=0x1d0007ff token=0xffe802e1 buffer=0x00000000
 1487337508.1385928972 uhci_dump_td#64@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487337508.1385938421 uhci_dump_td#64@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487337508.1385946581 uhci_dump_td#64@0: ios     =0 ls      =1 spd     =0
 1487337508.1385953024 uhci_dump_td#64@0: errcnt  =3 actlen  =0 pid=e1
 1487337508.1385961613 uhci_dump_td#64@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487337508.1385973639 uhci_idone#4@0: --- dump end ---
 1487337508.1385995973 uhci_idone#4@0: actlen=16, status=0x0
 1487337508.1386011434 uhci_idone#4@0: ux=0x3e08e00 done
 1487337508.1386024749 uhci_softintr#5@0: ux 0x3e08e00
 1487337508.1386048371 usb_transfer_complete#16@0: called!
 1487337508.1386059538 usb_transfer_complete#16@0: pipe = 0x32c3748 xfer = 0x3e08e00 status = 0 actlen = 16
 1487337508.1386074999 usb_transfer_complete#16@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.1386096044 usb_transfer_complete#16@0: short transfer 16 < 18
 1487337508.1386109788 usb_transfer_complete#16@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487337508.1386139423 uhci_device_ctrl_done#4@0: called!
 1487337508.1386166481 uhci_remove_ls_ctrl#4@0: called!
 1487337508.1386184090 uhci_remove_ls_ctrl#4@0: sqh 0xd22710
 1487337508.1386210289 uhci_find_prev_qh#4@0: called!
 1487337508.1386227898 uhci_find_prev_qh#4@0: pqh=0xd20740 sqh=0xd22710
 1487337508.1386280296 uhci_device_ctrl_done#4@0: length=16
 1487337508.1386307354 usb_transfer_complete#16@0: xfer 0x3e08e00 doing callback 0x0 status 16
 1487337508.1386321098 usb_transfer_complete#16@0: <- done xfer 0x3e08e00, wakeup
 1487337508.1386424176 usbd_start_next#16@0: called!
 1487337508.1386438349 usbd_start_next#16@0: pipe = 0x32c3748, xfer = 0x0
 1487337508.1386633338 uhci_free_stds#4@0: called!
 1487337508.1386644076 uhci_free_stds#4@0: ux=0x3e08e00
 1487337508.1386733410 usbd_free_xfer#12@0: called!
 1487337508.1386743288 usbd_free_xfer#12@0: 0x3e08e00
 1487337508.1386766910 usb_freemem#6@0: called!
 1487337508.1386787955 usb_freemem#6@0: frag=0xd5de00
 1487337508.1386830475 usbd_do_request_flags#12@0: returning err = 16
 1487337508.1386873854 usbd_new_device#1@0: addr=2, getting full desc failed, err = 16
 1487337508.1386906925 usbd_remove_device#1@0: called!
 1487337508.1386924104 usbd_remove_device#1@0: dev 0x375d7c0 up 0x58120
 1487337508.1386949874 usbd_ar_pipe#3@0: called!
 1487337508.1386961900 usbd_ar_pipe#3@0: pipe = 0x32c3748
 1487337508.1386978220 usbd_dump_queue#15@0: called!
 1487337508.1386988958 usbd_dump_queue#15@0: pipe = 0x32c3748
 1487337508.1387033195 usb_rem_task#3@0: called!
 1487337508.1431406127 usbd_clear_port_feature#4@0: called!
 1487337508.1431419871 usbd_clear_port_feature#4@0: dev 0x3e27298 port 1 sel 1
 1487337508.1431437910 usbd_do_request_flags#13@0: called!
 1487337508.1431458096 usbd_alloc_xfer#13@0: called!
 1487337508.1431517366 usbd_alloc_xfer#13@0: returns 0x3e08e00
 1487337508.1431559456 usbd_transfer#13@0: called!
 1487337508.1431573629 usbd_transfer#13@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337508.1431590379 usbd_dump_queue#16@0: called!
 1487337508.1431598110 usbd_dump_queue#16@0: pipe = 0x3e2d6c8
 1487337508.1431627316 usb_insert_transfer#13@0: called!
 1487337508.1431643207 usb_insert_transfer#13@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337508.1431663822 usb_insert_transfer#13@0: <- done xfer 0x3e08e00, err 0
 1487337508.1431682720 roothub_ctrl_start#9@0: called!
 1487337508.1431694746 roothub_ctrl_start#9@0: type=0x23 request=0x1
 1487337508.1431725669 uhci_roothub_ctrl#9@0: called!
 1487337508.1431742419 uhci_roothub_ctrl#9@0: type=0x23 request=01
 1487337508.1431764323 uhci_roothub_ctrl#9@0: UR_CLEAR_PORT_FEATURE port=1 feature=1
 1487337508.1431802978 uhci_roothub_ctrl#9@0: returning 0
 1487337508.1431821875 roothub_ctrl_start#9@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487337508.1431833472 roothub_ctrl_start#9@0: xfer 0x3e08e00 err 0
 1487337508.1431850222 usb_transfer_complete#17@0: called!
 1487337508.1431861388 usb_transfer_complete#17@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487337508.1431882004 usb_transfer_complete#17@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.1431900472 usb_transfer_complete#17@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337508.1431913357 usb_transfer_complete#17@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337508.1431927101 usb_transfer_complete#17@0: <- done xfer 0x3e08e00, wakeup
 1487337508.1431953729 usbd_start_next#17@0: called!
 1487337508.1431970479 usbd_start_next#17@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337508.1431993672 usbd_transfer#13@0: <- done transfer 0x3e08e00, err = 0
 1487337508.1432010852 usbd_transfer#13@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337508.1432033615 usbd_free_xfer#13@0: called!
 1487337508.1432044781 usbd_free_xfer#13@0: 0x3e08e00
 1487337508.1432267258 usb_needs_explore#2@0: called!
 1487337508.1432360458 usbd_get_port_status#4@0: called!
 1487337508.1432374202 usbd_get_port_status#4@0: dev 0x3e27298 port 1
 1487337508.1432389234 usbd_do_request_flags#14@0: called!
 1487337508.1432399542 usbd_alloc_xfer#14@0: called!
 1487337508.1432433471 usbd_alloc_xfer#14@0: returns 0x3e08e00
 1487337508.1432453228 usb_allocmem_flags#10@0: called!
 1487337508.1432473414 usb_allocmem_flags#10@0: use frag=0xd5de00 size=4
 1487337508.1432494889 usbd_transfer#14@0: called!
 1487337508.1432504338 usbd_transfer#14@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487337508.1432518511 usbd_dump_queue#17@0: called!
 1487337508.1432530107 usbd_dump_queue#17@0: pipe = 0x3e2d6c8
 1487337508.1432553729 usb_insert_transfer#14@0: called!
 1487337508.1432565325 usb_insert_transfer#14@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487337508.1432579499 usb_insert_transfer#14@0: <- done xfer 0x3e08e00, err 0
 1487337508.1432595819 roothub_ctrl_start#10@0: called!
 1487337508.1432606557 roothub_ctrl_start#10@0: type=0xa3 request= 0
 1487337508.1432628461 uhci_roothub_ctrl#10@0: called!
 1487337508.1432638339 uhci_roothub_ctrl#10@0: type=0xa3 request=00
 1487337508.1432672269 uhci_roothub_ctrl#10@0: returning 4
 1487337508.1432680000 roothub_ctrl_start#10@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487337508.1432688589 roothub_ctrl_start#10@0: xfer 0x3e08e00 err 0
 1487337508.1432702763 usb_transfer_complete#18@0: called!
 1487337508.1432713070 usb_transfer_complete#18@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487337508.1432727244 usb_transfer_complete#18@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487337508.1432739269 usb_transfer_complete#18@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487337508.1432753872 usb_transfer_complete#18@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487337508.1432764609 usb_transfer_complete#18@0: <- done xfer 0x3e08e00, wakeup
 1487337508.1432780501 usbd_start_next#18@0: called!
 1487337508.1432793385 usbd_start_next#18@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487337508.1432814001 usbd_transfer#14@0: <- done transfer 0x3e08e00, err = 0
 1487337508.1432825168 usbd_transfer#14@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487337508.1432840630 usbd_free_xfer#14@0: called!
 1487337508.1432851796 usbd_free_xfer#14@0: 0x3e08e00
 1487337508.1432871123 usb_freemem#7@0: called!
 1487337508.1432888733 usb_freemem#7@0: frag=0xd5de00
 1487337508.1625899713 uhci_poll_hub#43@0: called!
 1487337508.-1595157586 uhci_poll_hub#44@0: called!
 1487337508.-521631554 uhci_poll_hub#45@0: called!
 
 ---
 
 > I'd be interested in results from both this patch alone and combined 
 > with first one.
 
 It looks log from the second patch alone is similar to
 one without patches (more stalls):
  https://gist.github.com/tsutsui/0758138e3a21c7f59298db0a50f0cb2e
 
 ---
 Izumi Tsutsui
 



Home | Main Index | Thread Index | Old Index