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: Wed, 15 Feb 2017 21:54:51 +0900

 > Does this patch help?
 
 Still gets "uhub0: device problem, disabling port 1"
 
 ---
 Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
     2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017
     The NetBSD Foundation, Inc.  All rights reserved.
 Copyright (c) 1982, 1986, 1989, 1991, 1993
     The Regents of the University of California.  All rights reserved.
 
 NetBSD 7.99.59 (GENERIC_UHCI) #17: Wed Feb 15 21:34:42 JST 2017
         tsutsui@mirage:/usr/src/sys/arch/macppc/compile/GENERIC_UHCI
 total memory = 65536 KB
 avail memory = 51656 KB
 
  :
 
 uhci0 at pci0 dev 14 function 0: VIA Technologies VT83C572 USB Controller (rev. 0x04)
 uhci0: interrupting at irq 25
 usb0 at uhci0: USB revision 1.0
 
  :
 
 scsibus0: waiting 2 seconds for devices to settle...
 uhub0 at usb0: VIA Technologies UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
 uhub0: 2 ports with 2 removable, self powered
 adbkbd0 at nadb0 addr 2: extended keyboard
 wskbd0 at adbkbd0 mux 1
 wsmouse0 at adbkbd0 mux 0
 adbms0 at nadb0 addr 3: 1-button, 100 dpi mouse
 wsmouse1 at adbms0 mux 0
 uhub0: device problem, disabling port 1
 
 ---
 
 usbhist says:
 
 ---
 1487162395.544631903 uhci_poll_hub#1@0: called!
 1487162395.1618572823 uhci_poll_hub#2@0: called!
 1487162395.-1602882186 uhci_poll_hub#3@0: called!
 1487162395.-528772476 uhci_poll_hub#4@0: called!
 1487162395.-528679277 usb_transfer_complete#1@0: called!
 1487162395.-528659520 usb_transfer_complete#1@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487162395.-528632033 usb_transfer_complete#1@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487162395.-528604116 usb_transfer_complete#1@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487162395.-528568038 usb_transfer_complete#1@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487162395.-528507051 usb_needs_explore#1@0: called!
 1487162395.-528348139 usbd_start_next#1@0: called!
 1487162395.-528322370 usbd_start_next#1@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487162395.-528290158 uhci_root_intr_start#1@0: called!
 1487162395.-528274696 uhci_root_intr_start#1@0: xfer=0x3e08ee0 len=1 flags=132
 1487162395.-528012277 usb_event_thread#0@0: sc 0x3ecd0f8 woke up
 1487162395.-527976200 usb_discover#1@0: called!
 1487162395.-527898032 usbd_get_port_status#1@0: called!
 1487162395.-527880853 usbd_get_port_status#1@0: dev 0x3e27298 port 1
 1487162395.-527839192 usbd_do_request_flags#1@0: called!
 1487162395.-527805692 usbd_alloc_xfer#1@0: called!
 1487162395.-527714640 usbd_alloc_xfer#1@0: returns 0x3e08e00
 1487162395.-527672979 usb_allocmem_flags#1@0: called!
 1487162395.-527634325 usb_allocmem_flags#1@0: use frag=0xd5dec0 size=4
 1487162395.-527568183 usbd_transfer#1@0: called!
 1487162395.-527550574 usbd_transfer#1@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162395.-527521798 usbd_dump_queue#1@0: called!
 1487162395.-527504618 usbd_dump_queue#1@0: pipe = 0x3e2d6c8
 1487162395.-527456086 usb_insert_transfer#1@0: called!
 1487162395.-527438047 usb_insert_transfer#1@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162395.-527411848 usb_insert_transfer#1@0: <- done xfer 0x3e08e00, err 0
 1487162395.-527376201 roothub_ctrl_start#1@0: called!
 1487162395.-527355155 roothub_ctrl_start#1@0: type=0xa3 request= 0
 1487162395.-527295456 uhci_roothub_ctrl#1@0: called!
 1487162395.-527279995 uhci_roothub_ctrl#1@0: type=0xa3 request=00
 1487162395.-527237475 uhci_roothub_ctrl#1@0: returning 4
 1487162395.-527216859 roothub_ctrl_start#1@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487162395.-527200539 roothub_ctrl_start#1@0: xfer 0x3e08e00 err 0
 1487162395.-527182930 usb_transfer_complete#2@0: called!
 1487162395.-527175199 usb_transfer_complete#2@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487162395.-527161455 usb_transfer_complete#2@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162395.-527146852 usb_transfer_complete#2@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162395.-527127096 usb_transfer_complete#2@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162395.-527113781 usb_transfer_complete#2@0: <- done xfer 0x3e08e00, wakeup
 1487162395.-527090159 usbd_start_next#2@0: called!
 1487162395.-527078134 usbd_start_next#2@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162395.-527052364 usbd_transfer#1@0: <- done transfer 0x3e08e00, err = 0
 1487162395.-527030031 usbd_transfer#1@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162395.-526990947 usbd_free_xfer#1@0: called!
 1487162395.-526971620 usbd_free_xfer#1@0: 0x3e08e00
 1487162395.-526936831 usb_freemem#1@0: called!
 1487162395.-526910203 usb_freemem#1@0: frag=0xd5dec0
 1487162395.-526791663 usbd_clear_port_feature#1@0: called!
 1487162395.-526775342 usbd_clear_port_feature#1@0: dev 0x3e27298 port 1 sel 16
 1487162395.-526756015 usbd_do_request_flags#2@0: called!
 1487162395.-526745708 usbd_alloc_xfer#2@0: called!
 1487162395.-526717791 usbd_alloc_xfer#2@0: returns 0x3e08e00
 1487162395.-526702329 usbd_transfer#2@0: called!
 1487162395.-526694169 usbd_transfer#2@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162395.-526681284 usbd_dump_queue#2@0: called!
 1487162395.-526670117 usbd_dump_queue#2@0: pipe = 0x3e2d6c8
 1487162395.-526655085 usb_insert_transfer#2@0: called!
 1487162395.-526647784 usb_insert_transfer#2@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162395.-526638335 usb_insert_transfer#2@0: <- done xfer 0x3e08e00, err 0
 1487162395.-526623303 roothub_ctrl_start#2@0: called!
 1487162395.-526612565 roothub_ctrl_start#2@0: type=0x23 request=0x1
 1487162395.-526596245 uhci_roothub_ctrl#2@0: called!
 1487162395.-526590661 uhci_roothub_ctrl#2@0: type=0x23 request=01
 1487162395.-526572193 uhci_roothub_ctrl#2@0: UR_CLEAR_PORT_FEATURE port=1 feature=16
 1487162395.-526537834 uhci_roothub_ctrl#2@0: returning 0
 1487162395.-526527955 roothub_ctrl_start#2@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162395.-526522372 roothub_ctrl_start#2@0: xfer 0x3e08e00 err 0
 1487162395.-526508199 usb_transfer_complete#3@0: called!
 1487162395.-526496603 usb_transfer_complete#3@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162395.-526482859 usb_transfer_complete#3@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162395.-526473840 usb_transfer_complete#3@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162395.-526461384 usb_transfer_complete#3@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162395.-526452365 usb_transfer_complete#3@0: <- done xfer 0x3e08e00, wakeup
 1487162395.-526438621 usbd_start_next#3@0: called!
 1487162395.-526427025 usbd_start_next#3@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162395.-526410275 usbd_transfer#2@0: <- done transfer 0x3e08e00, err = 0
 1487162395.-526400826 usbd_transfer#2@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162395.-526388800 usbd_free_xfer#2@0: called!
 1487162395.-526379781 usbd_free_xfer#2@0: 0x3e08e00
 1487162396.544574887 uhci_poll_hub#5@0: called!
 1487162396.802434076 usbd_reset_port#1@0: called!
 1487162396.802457268 usbd_do_request_flags#3@0: called!
 1487162396.802474448 usbd_alloc_xfer#3@0: called!
 1487162396.802537154 usbd_alloc_xfer#3@0: returns 0x3e08e00
 1487162396.802572801 usbd_transfer#3@0: called!
 1487162396.802583539 usbd_transfer#3@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162396.802600289 usbd_dump_queue#3@0: called!
 1487162396.802612744 usbd_dump_queue#3@0: pipe = 0x3e2d6c8
 1487162396.802640232 usb_insert_transfer#3@0: called!
 1487162396.802651828 usb_insert_transfer#3@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162396.802666860 usb_insert_transfer#3@0: <- done xfer 0x3e08e00, err 0
 1487162396.802688335 roothub_ctrl_start#3@0: called!
 1487162396.802699931 roothub_ctrl_start#3@0: type=0x23 request=0x3
 1487162396.802725700 uhci_roothub_ctrl#3@0: called!
 1487162396.802734720 uhci_roothub_ctrl#3@0: type=0x23 request=03
 1487162396.802780675 uhci_portreset#1@0: called!
 1487162396.1618459543 uhci_poll_hub#6@0: called!
 1487162396.1618498197 usb_transfer_complete#4@0: called!
 1487162396.1618507217 usb_transfer_complete#4@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487162396.1618522678 usb_transfer_complete#4@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487162396.1618538999 usb_transfer_complete#4@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487162396.1618564339 usb_transfer_complete#4@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487162396.1618593544 usbd_start_next#4@0: called!
 1487162396.1618605999 usbd_start_next#4@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487162396.1618624897 uhci_root_intr_start#2@0: called!
 1487162396.1618636493 uhci_root_intr_start#2@0: xfer=0x3e08ee0 len=1 flags=132
 1487162396.1919107648 uhci_portreset#1@0: uhci port 1 reset, status0 = 0x038a
 1487162396.1919566344 uhci_portreset#1@0: uhci port 1 reset, status1 = 0x01ab
 1487162396.-2118097524 uhci_portreset#1@0: uhci port 1 iteration 9, status = 0x01af
 1487162396.-1860475843 uhci_portreset#1@0: uhci port 1 iteration 8, status = 0x01a5
 1487162396.-1860458664 uhci_portreset#1@0: uhci port 1 reset, status2 = 0x01a5
 1487162396.-1860414426 roothub_ctrl_start#3@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162396.-1860401112 roothub_ctrl_start#3@0: xfer 0x3e08e00 err 0
 1487162396.-1860367612 usb_transfer_complete#5@0: called!
 1487162396.-1860359022 usb_transfer_complete#5@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162396.-1860341842 usb_transfer_complete#5@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162396.-1860326810 usb_transfer_complete#5@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162396.-1860309201 usb_transfer_complete#5@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162396.-1860297175 usb_transfer_complete#5@0: <- done xfer 0x3e08e00, wakeup
 1487162396.-1860273983 usbd_start_next#5@0: called!
 1487162396.-1860256803 usbd_start_next#5@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162396.-1860232322 usbd_transfer#3@0: <- done transfer 0x3e08e00, err = 0
 1487162396.-1860220726 usbd_transfer#3@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162396.-1860178206 usbd_free_xfer#3@0: called!
 1487162396.-1860162315 usbd_free_xfer#3@0: 0x3e08e00
 1487162396.-1860072551 usbd_reset_port#1@0: port 1 reset done, error=0
 1487162396.-1602923311 uhci_poll_hub#7@0: called!
 1487162396.-1602702123 usbd_get_port_status#2@0: called!
 1487162396.-1602689668 usbd_get_port_status#2@0: dev 0x3e27298 port 1
 1487162396.-1602666475 usbd_do_request_flags#4@0: called!
 1487162396.-1602648866 usbd_alloc_xfer#4@0: called!
 1487162396.-1602586160 usbd_alloc_xfer#4@0: returns 0x3e08e00
 1487162396.-1602552231 usb_allocmem_flags#2@0: called!
 1487162396.-1602517012 usb_allocmem_flags#2@0: use frag=0xd5dec0 size=4
 1487162396.-1602474063 usbd_transfer#4@0: called!
 1487162396.-1602462037 usbd_transfer#4@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162396.-1602443999 usbd_dump_queue#4@0: called!
 1487162396.-1602433262 usbd_dump_queue#4@0: pipe = 0x3e2d6c8
 1487162396.-1602405774 usb_insert_transfer#4@0: called!
 1487162396.-1602395037 usb_insert_transfer#4@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162396.-1602376998 usb_insert_transfer#4@0: <- done xfer 0x3e08e00, err 0
 1487162396.-1602353806 roothub_ctrl_start#4@0: called!
 1487162396.-1602343068 roothub_ctrl_start#4@0: type=0xa3 request= 0
 1487162396.-1602309568 uhci_roothub_ctrl#4@0: called!
 1487162396.-1602298401 uhci_roothub_ctrl#4@0: type=0xa3 request=00
 1487162396.-1602272202 uhci_roothub_ctrl#4@0: returning 4
 1487162396.-1602260606 roothub_ctrl_start#4@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487162396.-1602248580 roothub_ctrl_start#4@0: xfer 0x3e08e00 err 0
 1487162396.-1602230971 usb_transfer_complete#6@0: called!
 1487162396.-1602220234 usb_transfer_complete#6@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487162396.-1602206920 usb_transfer_complete#6@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162396.-1602194035 usb_transfer_complete#6@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162396.-1602174278 usb_transfer_complete#6@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162396.-1602160964 usb_transfer_complete#6@0: <- done xfer 0x3e08e00, wakeup
 1487162396.-1602141208 usbd_start_next#6@0: called!
 1487162396.-1602127034 usbd_start_next#6@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162396.-1602106848 usbd_transfer#4@0: <- done transfer 0x3e08e00, err = 0
 1487162396.-1602096540 usbd_transfer#4@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162396.-1602078502 usbd_free_xfer#4@0: called!
 1487162396.-1602068194 usbd_free_xfer#4@0: 0x3e08e00
 1487162396.-1602040707 usb_freemem#2@0: called!
 1487162396.-1602019662 usb_freemem#2@0: frag=0xd5dec0
 1487162396.-1601936770 usbd_clear_port_feature#2@0: called!
 1487162396.-1601926891 usbd_clear_port_feature#2@0: dev 0x3e27298 port 1 sel 20
 1487162396.-1601912289 usbd_do_request_flags#5@0: called!
 1487162396.-1601901122 usbd_alloc_xfer#5@0: called!
 1487162396.-1601875353 usbd_alloc_xfer#5@0: returns 0x3e08e00
 1487162396.-1601859461 usbd_transfer#5@0: called!
 1487162396.-1601851301 usbd_transfer#5@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162396.-1601837557 usbd_dump_queue#5@0: called!
 1487162396.-1601828538 usbd_dump_queue#5@0: pipe = 0x3e2d6c8
 1487162396.-1601814365 usb_insert_transfer#5@0: called!
 1487162396.-1601805775 usb_insert_transfer#5@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162396.-1601794608 usb_insert_transfer#5@0: <- done xfer 0x3e08e00, err 0
 1487162396.-1601781723 roothub_ctrl_start#5@0: called!
 1487162396.-1601769698 roothub_ctrl_start#5@0: type=0x23 request=0x1
 1487162396.-1601755095 uhci_roothub_ctrl#5@0: called!
 1487162396.-1601746935 uhci_roothub_ctrl#5@0: type=0x23 request=01
 1487162396.-1601735338 uhci_roothub_ctrl#5@0: UR_CLEAR_PORT_FEATURE port=1 feature=20
 1487162396.-1601715582 uhci_roothub_ctrl#5@0: returning 0
 1487162396.-1601703986 roothub_ctrl_start#5@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162396.-1601695396 roothub_ctrl_start#5@0: xfer 0x3e08e00 err 0
 1487162396.-1601684229 usb_transfer_complete#7@0: called!
 1487162396.-1601673492 usb_transfer_complete#7@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162396.-1601659318 usb_transfer_complete#7@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162396.-1601649011 usb_transfer_complete#7@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162396.-1601639562 usb_transfer_complete#7@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162396.-1601630113 usb_transfer_complete#7@0: <- done xfer 0x3e08e00, wakeup
 1487162396.-1601615081 usbd_start_next#7@0: called!
 1487162396.-1601602196 usbd_start_next#7@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162396.-1601586305 usbd_transfer#5@0: <- done transfer 0x3e08e00, err = 0
 1487162396.-1601576856 usbd_transfer#5@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162396.-1601563971 usbd_free_xfer#5@0: called!
 1487162396.-1601552805 usbd_free_xfer#5@0: 0x3e08e00
 1487162396.-529021045 uhci_poll_hub#8@0: called!
 1487162396.-486055180 usbd_new_device#1@0: called!
 1487162396.-486035852 usbd_new_device#1@0: bus=0x3e3200c port=1 depth=1 speed=1
 1487162396.-485898845 usbd_setup_pipe_flags#1@0: called!
 1487162396.-485847306 usbd_setup_pipe_flags#1@0: dev=0x375d860 addr=0 iface=0x0 ep=0x375d884 pipe=0xfdc056a6
 1487162396.-485809081 uhci_open#1@0: called!
 1487162396.-485791902 uhci_open#1@0: pipe=0x39f9d88, addr=0, endpt=0 (1)
 1487162396.-485754106 uhci_alloc_sqh#1@0: called!
 1487162396.-485715452 uhci_alloc_std#1@0: called!
 1487162396.-485681093 uhci_alloc_std#2@0: called!
 1487162396.-485657900 usb_allocmem_flags#3@0: called!
 1487162396.-485628265 usb_allocmem_flags#3@0: use frag=0xd5dec0 size=8
 1487162396.-485597772 usbd_setup_pipe_flags#1@0: pipe=0x39f9d88
 1487162396.-485560406 usbd_get_initial_ddesc#1@0: called!
 1487162396.-485544515 usbd_get_initial_ddesc#1@0: dev 0x375d860
 1487162396.-485521322 usbd_do_request_flags#6@0: called!
 1487162396.-485506719 usbd_alloc_xfer#6@0: called!
 1487162396.-485451745 usbd_alloc_xfer#6@0: returns 0x3e08e00
 1487162396.-485434135 usb_allocmem_flags#4@0: called!
 1487162396.-485420392 usb_allocmem_flags#4@0: use frag=0xd5de80 size=64
 1487162396.-485393334 uhci_device_ctrl_init#1@0: called!
 1487162396.-485374436 uhci_device_ctrl_init#1@0: xfer=0x3e08e00 len=64, addr=0, endpt=0
 1487162396.-485337929 uhci_alloc_std_chain#1@0: called!
 1487162396.-485322038 uhci_alloc_std_chain#1@0: xfer=0x3e08e00 pipe=0x39f9d88
 1487162396.-485301423 uhci_alloc_std_chain#1@0: maxp=8 ntd=8
 1487162396.-485245159 uhci_alloc_std#3@0: called!
 1487162396.-485228839 uhci_alloc_std#4@0: called!
 1487162396.-485212088 uhci_alloc_std#5@0: called!
 1487162396.-485201781 uhci_alloc_std#6@0: called!
 1487162396.-485187178 uhci_alloc_std#7@0: called!
 1487162396.-485173434 uhci_alloc_std#8@0: called!
 1487162396.-485157543 uhci_alloc_std#9@0: called!
 1487162396.-485143799 uhci_alloc_std#10@0: called!
 1487162396.-485096985 usbd_transfer#6@0: called!
 1487162396.-485080664 usbd_transfer#6@0: xfer = 0x3e08e00, flags = 0x6, pipe = 0x39f9d88, running = 0
 1487162396.-485063914 usbd_dump_queue#6@0: called!
 1487162396.-485054895 usbd_dump_queue#6@0: pipe = 0x39f9d88
 1487162396.-485029125 usb_insert_transfer#6@0: called!
 1487162396.-485017099 usb_insert_transfer#6@0: xfer = 0x3e08e00 pipe = 0x39f9d88 running = 0 timeout = 5000
 1487162396.-485000349 usb_insert_transfer#6@0: <- done xfer 0x3e08e00, err 0
 1487162396.-484966849 uhci_device_ctrl_start#1@0: called!
 1487162396.-484939362 uhci_device_ctrl_start#1@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487162396.-484920464 uhci_device_ctrl_start#1@0: len=64, addr=0, endpt=0
 1487162396.-484867207 uhci_reset_std_chain#1@0: called!
 1487162396.-484853034 uhci_reset_std_chain#1@0: xfer=0x3e08e00 len 64 isread 128 toggle 1
 1487162396.-484737930 uhci_device_ctrl_start#1@0: --- dump start ---
 1487162396.-484720751 uhci_device_ctrl_start#1@0: before transfer
 1487162396.-484689827 uhci_dump_td#1@0: called!
 1487162396.-484671789 uhci_dump_td#1@0: TD(0xd24770) at 0x00d24770
 1487162396.-484653750 uhci_dump_td#1@0:    link=0x00d245f0 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487162396.-484636141 uhci_dump_td#1@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484614666 uhci_dump_td#1@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484596628 uhci_dump_td#1@0: ios     =0 ls      =1 spd     =0
 1487162396.-484578160 uhci_dump_td#1@0: errcnt  =3 actlen  =1024 pid=2d
 1487162396.-484557973 uhci_dump_td#1@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-484532633 uhci_dump_td#2@0: called!
 1487162396.-484526621 uhci_dump_td#2@0: TD(0xd245f0) at 0x00d245f0
 1487162396.-484518890 uhci_dump_td#2@0:    link=0x00d24624 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487162396.-484510729 uhci_dump_td#2@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484502569 uhci_dump_td#2@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484495268 uhci_dump_td#2@0: ios     =0 ls      =1 spd     =1
 1487162396.-484486248 uhci_dump_td#2@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484478518 uhci_dump_td#2@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-484468210 uhci_dump_td#3@0: called!
 1487162396.-484461767 uhci_dump_td#3@0: TD(0xd24620) at 0x00d24620
 1487162396.-484452319 uhci_dump_td#3@0:    link=0x00d24654 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de88
 1487162396.-484444158 uhci_dump_td#3@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484435998 uhci_dump_td#3@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484428697 uhci_dump_td#3@0: ios     =0 ls      =1 spd     =1
 1487162396.-484418818 uhci_dump_td#3@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484409799 uhci_dump_td#3@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-484399491 uhci_dump_td#4@0: called!
 1487162396.-484393049 uhci_dump_td#4@0: TD(0xd24650) at 0x00d24650
 1487162396.-484385318 uhci_dump_td#4@0:    link=0x00d24684 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de90
 1487162396.-484377587 uhci_dump_td#4@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484369427 uhci_dump_td#4@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484362555 uhci_dump_td#4@0: ios     =0 ls      =1 spd     =1
 1487162396.-484354395 uhci_dump_td#4@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484345805 uhci_dump_td#4@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-484335497 uhci_dump_td#5@0: called!
 1487162396.-484329055 uhci_dump_td#5@0: TD(0xd24680) at 0x00d24680
 1487162396.-484319606 uhci_dump_td#5@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487162396.-484311446 uhci_dump_td#5@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484303285 uhci_dump_td#5@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484296843 uhci_dump_td#5@0: ios     =0 ls      =1 spd     =1
 1487162396.-484287394 uhci_dump_td#5@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484279234 uhci_dump_td#5@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-484268067 uhci_dump_td#6@0: called!
 1487162396.-484262054 uhci_dump_td#6@0: TD(0xd246b0) at 0x00d246b0
 1487162396.-484253894 uhci_dump_td#6@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487162396.-484245733 uhci_dump_td#6@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484237573 uhci_dump_td#6@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484231131 uhci_dump_td#6@0: ios     =0 ls      =1 spd     =1
 1487162396.-484221682 uhci_dump_td#6@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484213092 uhci_dump_td#6@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-484202355 uhci_dump_td#7@0: called!
 1487162396.-484196342 uhci_dump_td#7@0: TD(0xd246e0) at 0x00d246e0
 1487162396.-484186893 uhci_dump_td#7@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487162396.-484178733 uhci_dump_td#7@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484170572 uhci_dump_td#7@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484164130 uhci_dump_td#7@0: ios     =0 ls      =1 spd     =1
 1487162396.-484153822 uhci_dump_td#7@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484145232 uhci_dump_td#7@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-484134495 uhci_dump_td#8@0: called!
 1487162396.-484128482 uhci_dump_td#8@0: TD(0xd24710) at 0x00d24710
 1487162396.-484119033 uhci_dump_td#8@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487162396.-484110873 uhci_dump_td#8@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484102713 uhci_dump_td#8@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484096270 uhci_dump_td#8@0: ios     =0 ls      =1 spd     =1
 1487162396.-484085963 uhci_dump_td#8@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484077373 uhci_dump_td#8@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-484066636 uhci_dump_td#9@0: called!
 1487162396.-484059764 uhci_dump_td#9@0: TD(0xd24740) at 0x00d24740
 1487162396.-484052462 uhci_dump_td#9@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487162396.-484044302 uhci_dump_td#9@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-484036142 uhci_dump_td#9@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-484029699 uhci_dump_td#9@0: ios     =0 ls      =1 spd     =1
 1487162396.-484019821 uhci_dump_td#9@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-484010372 uhci_dump_td#9@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-484000064 uhci_dump_td#10@0: called!
 1487162396.-483993622 uhci_dump_td#10@0: TD(0xd247a0) at 0x00d247a0
 1487162396.-483985032 uhci_dump_td#10@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487162396.-483976872 uhci_dump_td#10@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483968712 uhci_dump_td#10@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162396.-483962269 uhci_dump_td#10@0: ios     =0 ls      =1 spd     =0
 1487162396.-483952820 uhci_dump_td#10@0: errcnt  =3 actlen  =1024 pid=e1
 1487162396.-483944660 uhci_dump_td#10@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162396.-483928339 uhci_device_ctrl_start#1@0: --- dump end ---
 1487162396.-483899134 uhci_add_ls_ctrl#1@0: called!
 1487162396.-483882384 uhci_add_ls_ctrl#1@0: sqh 0xd22710
 1487162396.-483844159 uhci_device_ctrl_start#1@0: --- dump start ---
 1487162396.-483827409 uhci_device_ctrl_start#1@0: follow from [0]
 1487162396.-483808082 uhci_dump_td#11@0: called!
 1487162396.-483792191 uhci_dump_td#11@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487162396.-483784030 uhci_dump_td#11@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487162396.-483775870 uhci_dump_td#11@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483769857 uhci_dump_td#11@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162396.-483760408 uhci_dump_td#11@0: ios     =1 ls      =0 spd     =0
 1487162396.-483752248 uhci_dump_td#11@0: errcnt  =0 actlen  =1 pid=00
 1487162396.-483743658 uhci_dump_td#11@0: addr=0  endpt=0  D=0  maxlen=1,
 1487162396.-483720895 uhci_dump_qh#1@0: called!
 1487162396.-483700280 uhci_dump_qh#1@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162396.-483680094 uhci_dump_qh#2@0: called!
 1487162396.-483671074 uhci_dump_qh#2@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162396.-483658619 uhci_dump_qh#3@0: called!
 1487162396.-483650888 uhci_dump_qh#3@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487162396.-483641439 uhci_dump_qh#4@0: called!
 1487162396.-483633279 uhci_dump_qh#4@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162396.-483625548 uhci_dump_qh#5@0: called!
 1487162396.-483614811 uhci_dump_qh#5@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487162396.-483605362 uhci_dump_qh#6@0: called!
 1487162396.-483589471 uhci_dump_qh#6@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487162396.-483582170 uhci_dump_qh#7@0: called!
 1487162396.-483569714 uhci_dump_qh#7@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487162396.-483554253 uhci_device_ctrl_start#1@0: Enqueued QH:
 1487162396.-483540509 uhci_dump_qh#8@0: called!
 1487162396.-483534067 uhci_dump_qh#8@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162396.-483523759 uhci_dump_td#12@0: called!
 1487162396.-483515598 uhci_dump_td#12@0: TD(0xd24770) at 0x00d24770
 1487162396.-483507438 uhci_dump_td#12@0:    link=0x00d245f0 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487162396.-483500566 uhci_dump_td#12@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483491976 uhci_dump_td#12@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483483816 uhci_dump_td#12@0: ios     =0 ls      =1 spd     =0
 1487162396.-483474797 uhci_dump_td#12@0: errcnt  =3 actlen  =1024 pid=2d
 1487162396.-483468354 uhci_dump_td#12@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-483456329 uhci_dump_td#13@0: called!
 1487162396.-483448598 uhci_dump_td#13@0: TD(0xd245f0) at 0x00d245f0
 1487162396.-483440437 uhci_dump_td#13@0:    link=0x00d24624 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487162396.-483434425 uhci_dump_td#13@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483424976 uhci_dump_td#13@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483416815 uhci_dump_td#13@0: ios     =0 ls      =1 spd     =1
 1487162396.-483407796 uhci_dump_td#13@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483400495 uhci_dump_td#13@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-483389757 uhci_dump_td#14@0: called!
 1487162396.-483382027 uhci_dump_td#14@0: TD(0xd24620) at 0x00d24620
 1487162396.-483373866 uhci_dump_td#14@0:    link=0x00d24654 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de88
 1487162396.-483366994 uhci_dump_td#14@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483357975 uhci_dump_td#14@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483349815 uhci_dump_td#14@0: ios     =0 ls      =1 spd     =1
 1487162396.-483340795 uhci_dump_td#14@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483333065 uhci_dump_td#14@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-483321468 uhci_dump_td#15@0: called!
 1487162396.-483313308 uhci_dump_td#15@0: TD(0xd24650) at 0x00d24650
 1487162396.-483304718 uhci_dump_td#15@0:    link=0x00d24684 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de90
 1487162396.-483298705 uhci_dump_td#15@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483290116 uhci_dump_td#15@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483281955 uhci_dump_td#15@0: ios     =0 ls      =1 spd     =1
 1487162396.-483272936 uhci_dump_td#15@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483265635 uhci_dump_td#15@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-483254897 uhci_dump_td#16@0: called!
 1487162396.-483245878 uhci_dump_td#16@0: TD(0xd24680) at 0x00d24680
 1487162396.-483237718 uhci_dump_td#16@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487162396.-483231275 uhci_dump_td#16@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483221826 uhci_dump_td#16@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483213666 uhci_dump_td#16@0: ios     =0 ls      =1 spd     =1
 1487162396.-483204647 uhci_dump_td#16@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483196916 uhci_dump_td#16@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-483186179 uhci_dump_td#17@0: called!
 1487162396.-483178018 uhci_dump_td#17@0: TD(0xd246b0) at 0x00d246b0
 1487162396.-483169858 uhci_dump_td#17@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487162396.-483163416 uhci_dump_td#17@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483155255 uhci_dump_td#17@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483147095 uhci_dump_td#17@0: ios     =0 ls      =1 spd     =1
 1487162396.-483138935 uhci_dump_td#17@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483132922 uhci_dump_td#17@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-483122184 uhci_dump_td#18@0: called!
 1487162396.-483111877 uhci_dump_td#18@0: TD(0xd246e0) at 0x00d246e0
 1487162396.-483103287 uhci_dump_td#18@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487162396.-483096845 uhci_dump_td#18@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483087825 uhci_dump_td#18@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483079665 uhci_dump_td#18@0: ios     =0 ls      =1 spd     =1
 1487162396.-483071075 uhci_dump_td#18@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483064633 uhci_dump_td#18@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-483054325 uhci_dump_td#19@0: called!
 1487162396.-483045306 uhci_dump_td#19@0: TD(0xd24710) at 0x00d24710
 1487162396.-483038004 uhci_dump_td#19@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487162396.-483031991 uhci_dump_td#19@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-483023402 uhci_dump_td#19@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-483015241 uhci_dump_td#19@0: ios     =0 ls      =1 spd     =1
 1487162396.-483007510 uhci_dump_td#19@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-483000638 uhci_dump_td#19@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-482989472 uhci_dump_td#20@0: called!
 1487162396.-482981311 uhci_dump_td#20@0: TD(0xd24740) at 0x00d24740
 1487162396.-482972722 uhci_dump_td#20@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487162396.-482966279 uhci_dump_td#20@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-482956830 uhci_dump_td#20@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-482949100 uhci_dump_td#20@0: ios     =0 ls      =1 spd     =1
 1487162396.-482940939 uhci_dump_td#20@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-482934067 uhci_dump_td#20@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-482922042 uhci_dump_td#21@0: called!
 1487162396.-482910445 uhci_dump_td#21@0: TD(0xd247a0) at 0x00d247a0
 1487162396.-482902285 uhci_dump_td#21@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487162396.-482895413 uhci_dump_td#21@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-482886394 uhci_dump_td#21@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162396.-482878234 uhci_dump_td#21@0: ios     =0 ls      =1 spd     =0
 1487162396.-482870503 uhci_dump_td#21@0: errcnt  =3 actlen  =1024 pid=e1
 1487162396.-482864490 uhci_dump_td#21@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162396.-482848599 uhci_device_ctrl_start#1@0: --- dump end ---
 1487162396.-482777733 usbd_transfer#6@0: <- done transfer 0x3e08e00, err = 1
 1487162396.-482753252 usbd_transfer#6@0: <- sleeping on xfer 0x3e08e00
 1487162396.-473384761 uhci_intr#1@0: called!
 1487162396.-473332363 uhci_intr1#1@0: called!
 1487162396.-473315183 uhci_intr1#1@0: sc 0x3e32008
 1487162396.-473282113 uhci_dumpregs#1@0: called!
 1487162396.-473266221 uhci_dumpregs#1@0: cmd =0081  sts    =0001  intr   =000f  frnum =0446
 1487162396.-473238734 uhci_dumpregs#1@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487162396.-473173881 usb_schedsoftintr#1@0: called!
 1487162396.-473153265 usb_schedsoftintr#1@0: polling=0
 1487162396.-473106880 uhci_intr1#1@0: sc 0x3e32008 done
 1487162396.-472972020 uhci_softintr#1@0: called!
 1487162396.-472955699 uhci_softintr#1@0: sc 0x3e32008
 1487162396.-472914039 uhci_check_intr#1@0: called!
 1487162396.-472899436 uhci_check_intr#1@0: ux 0x3e08e00
 1487162396.-472868942 uhci_check_intr#1@0: active ux=0x3e08e00
 1487162396.-472831576 uhci_check_intr#1@0: ux=0x3e08e00 done
 1487162396.-472768871 uhci_idone#1@0: called!
 1487162396.-472752979 uhci_idone#1@0: ux=0x3e08e00
 1487162396.-472725492 uhci_idone#1@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x39f9d88 ready
 1487162396.-472710030 uhci_idone#1@0: --- dump start ---
 1487162396.-472689415 uhci_dump_td#22@0: called!
 1487162396.-472682972 uhci_dump_td#22@0: TD(0xd24770) at 0x00d24770
 1487162396.-472671806 uhci_dump_td#22@0:    link=0x00d245f0 status=0x1c000007 token=0x00e0002d buffer=0x00d5dec0
 1487162396.-472659780 uhci_dump_td#22@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472641312 uhci_dump_td#22@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162396.-472631004 uhci_dump_td#22@0: ios     =0 ls      =1 spd     =0
 1487162396.-472619408 uhci_dump_td#22@0: errcnt  =3 actlen  =8 pid=2d
 1487162396.-472604805 uhci_dump_td#22@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-472588914 uhci_dump_td#23@0: called!
 1487162396.-472582471 uhci_dump_td#23@0: TD(0xd245f0) at 0x00d245f0
 1487162396.-472573023 uhci_dump_td#23@0:    link=0x00d24624 status=0x1c000007 token=0x00e80069 buffer=0x00d5de80
 1487162396.-472564862 uhci_dump_td#23@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472557132 uhci_dump_td#23@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162396.-472550689 uhci_dump_td#23@0: ios     =0 ls      =1 spd     =0
 1487162396.-472541240 uhci_dump_td#23@0: errcnt  =3 actlen  =8 pid=69
 1487162396.-472533080 uhci_dump_td#23@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-472521913 uhci_dump_td#24@0: called!
 1487162396.-472515471 uhci_dump_td#24@0: TD(0xd24620) at 0x00d24620
 1487162396.-472506022 uhci_dump_td#24@0:    link=0x00d24654 status=0x1c000007 token=0x00e00069 buffer=0x00d5de88
 1487162396.-472497862 uhci_dump_td#24@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472489701 uhci_dump_td#24@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162396.-472483259 uhci_dump_td#24@0: ios     =0 ls      =1 spd     =0
 1487162396.-472472951 uhci_dump_td#24@0: errcnt  =3 actlen  =8 pid=69
 1487162396.-472464791 uhci_dump_td#24@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-472454054 uhci_dump_td#25@0: called!
 1487162396.-472448041 uhci_dump_td#25@0: TD(0xd24650) at 0x00d24650
 1487162396.-472439880 uhci_dump_td#25@0:    link=0x00d24684 status=0x1c4007ff token=0x00e80069 buffer=0x00d5de90
 1487162396.-472431720 uhci_dump_td#25@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472423560 uhci_dump_td#25@0: dbuffer =0 stalled =1 active  =0 ioc     =0
 1487162396.-472415829 uhci_dump_td#25@0: ios     =0 ls      =1 spd     =0
 1487162396.-472405521 uhci_dump_td#25@0: errcnt  =3 actlen  =0 pid=69
 1487162396.-472397361 uhci_dump_td#25@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-472386194 uhci_dump_td#26@0: called!
 1487162396.-472379752 uhci_dump_td#26@0: TD(0xd24680) at 0x00d24680
 1487162396.-472370303 uhci_dump_td#26@0:    link=0x00d246b4 status=0x3c8003ff token=0x00e00069 buffer=0x00d5de98
 1487162396.-472362143 uhci_dump_td#26@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472353982 uhci_dump_td#26@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-472347540 uhci_dump_td#26@0: ios     =0 ls      =1 spd     =1
 1487162396.-472337232 uhci_dump_td#26@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-472329072 uhci_dump_td#26@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-472318334 uhci_dump_td#27@0: called!
 1487162396.-472311892 uhci_dump_td#27@0: TD(0xd246b0) at 0x00d246b0
 1487162396.-472302443 uhci_dump_td#27@0:    link=0x00d246e4 status=0x3c8003ff token=0x00e80069 buffer=0x00d5dea0
 1487162396.-472294283 uhci_dump_td#27@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472286123 uhci_dump_td#27@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-472280110 uhci_dump_td#27@0: ios     =0 ls      =1 spd     =1
 1487162396.-472271090 uhci_dump_td#27@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-472262071 uhci_dump_td#27@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-472251763 uhci_dump_td#28@0: called!
 1487162396.-472245321 uhci_dump_td#28@0: TD(0xd246e0) at 0x00d246e0
 1487162396.-472235872 uhci_dump_td#28@0:    link=0x00d24714 status=0x3c8003ff token=0x00e00069 buffer=0x00d5dea8
 1487162396.-472227712 uhci_dump_td#28@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472219551 uhci_dump_td#28@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-472212680 uhci_dump_td#28@0: ios     =0 ls      =1 spd     =1
 1487162396.-472202372 uhci_dump_td#28@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-472193353 uhci_dump_td#28@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-472182615 uhci_dump_td#29@0: called!
 1487162396.-472176173 uhci_dump_td#29@0: TD(0xd24710) at 0x00d24710
 1487162396.-472168013 uhci_dump_td#29@0:    link=0x00d24744 status=0x3c8003ff token=0x00e80069 buffer=0x00d5deb0
 1487162396.-472159852 uhci_dump_td#29@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472151692 uhci_dump_td#29@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-472144391 uhci_dump_td#29@0: ios     =0 ls      =1 spd     =1
 1487162396.-472134942 uhci_dump_td#29@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-472125493 uhci_dump_td#29@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162396.-472114756 uhci_dump_td#30@0: called!
 1487162396.-472108313 uhci_dump_td#30@0: TD(0xd24740) at 0x00d24740
 1487162396.-472098864 uhci_dump_td#30@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e00069 buffer=0x00d5deb8
 1487162396.-472090704 uhci_dump_td#30@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472082544 uhci_dump_td#30@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162396.-472076101 uhci_dump_td#30@0: ios     =0 ls      =1 spd     =1
 1487162396.-472065794 uhci_dump_td#30@0: errcnt  =3 actlen  =1024 pid=69
 1487162396.-472057633 uhci_dump_td#30@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162396.-472046896 uhci_dump_td#31@0: called!
 1487162396.-472040454 uhci_dump_td#31@0: TD(0xd247a0) at 0x00d247a0
 1487162396.-472031005 uhci_dump_td#31@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487162396.-472022845 uhci_dump_td#31@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-472014684 uhci_dump_td#31@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162396.-472008242 uhci_dump_td#31@0: ios     =0 ls      =1 spd     =0
 1487162396.-471997934 uhci_dump_td#31@0: errcnt  =3 actlen  =1024 pid=e1
 1487162396.-471989774 uhci_dump_td#31@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162396.-471974312 uhci_idone#1@0: --- dump end ---
 1487162396.-471944248 uhci_idone#1@0: actlen=16, status=0x400000
 1487162396.-471921055 uhci_idone#1@0: error, addr=0, endpt=0x00
 1487162396.-471900869 uhci_idone#1@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162396.-471880253 uhci_idone#1@0: dbuffer =0 stalled =1 active  =0
 1487162396.-471854054 uhci_idone#1@0: ux=0x3e08e00 done
 1487162396.-471830003 uhci_softintr#1@0: ux 0x3e08e00
 1487162396.-471811535 usb_transfer_complete#8@0: called!
 1487162396.-471800798 usb_transfer_complete#8@0: pipe = 0x39f9d88 xfer = 0x3e08e00 status = 17 actlen = 16
 1487162396.-471786195 usb_transfer_complete#8@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162396.-471772451 usb_transfer_complete#8@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487162396.-471738951 uhci_device_ctrl_done#1@0: called!
 1487162396.-471699008 uhci_remove_ls_ctrl#1@0: called!
 1487162396.-471683976 uhci_remove_ls_ctrl#1@0: sqh 0xd22710
 1487162396.-471620841 uhci_find_prev_qh#1@0: called!
 1487162396.-471603232 uhci_find_prev_qh#1@0: pqh=0xd20740 sqh=0xd22710
 1487162396.-471543962 uhci_device_ctrl_done#1@0: length=16
 1487162396.-471517333 usb_transfer_complete#8@0: xfer 0x3e08e00 doing callback 0x0 status 17
 1487162396.-471501872 usb_transfer_complete#8@0: <- done xfer 0x3e08e00, wakeup
 1487162396.-471387198 usbd_start_next#8@0: called!
 1487162396.-471372595 usbd_start_next#8@0: pipe = 0x39f9d88, xfer = 0x0
 1487162396.-471165151 uhci_free_stds#1@0: called!
 1487162396.-471147542 uhci_free_stds#1@0: ux=0x3e08e00
 1487162396.-471044034 usbd_free_xfer#6@0: called!
 1487162396.-471032867 usbd_free_xfer#6@0: 0x3e08e00
 1487162396.-471010104 usb_freemem#3@0: called!
 1487162396.-470984764 usb_freemem#3@0: frag=0xd5de80
 1487162396.-470932366 usbd_do_request_flags#6@0: returning err = 17
 1487162396.-469147831 uhci_intr#2@0: called!
 1487162396.-469123779 uhci_intr1#2@0: called!
 1487162396.-469112183 uhci_intr1#2@0: sc 0x3e32008
 1487162396.-469092856 uhci_dumpregs#2@0: called!
 1487162396.-469082548 uhci_dumpregs#2@0: cmd =0081  sts    =0002  intr   =000f  frnum =0447
 1487162396.-469063650 uhci_dumpregs#2@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487162396.-469024996 usb_schedsoftintr#2@0: called!
 1487162396.-469010823 usb_schedsoftintr#2@0: polling=0
 1487162396.-468980759 uhci_intr1#2@0: sc 0x3e32008 done
 1487162396.-468907745 uhci_softintr#2@0: called!
 1487162396.-468896578 uhci_softintr#2@0: sc 0x3e32008
 1487162397.415911898 usbd_get_initial_ddesc#2@0: called!
 1487162397.415923064 usbd_get_initial_ddesc#2@0: dev 0x375d860
 1487162397.415938526 usbd_do_request_flags#7@0: called!
 1487162397.415961289 usbd_alloc_xfer#7@0: called!
 1487162397.416043322 usbd_alloc_xfer#7@0: returns 0x3e08e00
 1487162397.416069950 usb_allocmem_flags#5@0: called!
 1487162397.416098726 usb_allocmem_flags#5@0: use frag=0xd5de80 size=8
 1487162397.416127502 uhci_device_ctrl_init#2@0: called!
 1487162397.416138239 uhci_device_ctrl_init#2@0: xfer=0x3e08e00 len=8, addr=0, endpt=0
 1487162397.416159284 uhci_alloc_std_chain#2@0: called!
 1487162397.416168304 uhci_alloc_std_chain#2@0: xfer=0x3e08e00 pipe=0x39f9d88
 1487162397.416180330 uhci_alloc_std_chain#2@0: maxp=8 ntd=1
 1487162397.416248619 uhci_alloc_std#11@0: called!
 1487162397.416292856 usbd_transfer#7@0: called!
 1487162397.416303164 usbd_transfer#7@0: xfer = 0x3e08e00, flags = 0x6, pipe = 0x39f9d88, running = 0
 1487162397.416322921 usbd_dump_queue#7@0: called!
 1487162397.416333228 usbd_dump_queue#7@0: pipe = 0x39f9d88
 1487162397.416359857 usb_insert_transfer#7@0: called!
 1487162397.416368447 usb_insert_transfer#7@0: xfer = 0x3e08e00 pipe = 0x39f9d88 running = 0 timeout = 5000
 1487162397.416385197 usb_insert_transfer#7@0: <- done xfer 0x3e08e00, err 0
 1487162397.416406671 uhci_device_ctrl_start#2@0: called!
 1487162397.416420415 uhci_device_ctrl_start#2@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487162397.416430293 uhci_device_ctrl_start#2@0: len=8, addr=0, endpt=0
 1487162397.416456922 uhci_reset_std_chain#2@0: called!
 1487162397.416468089 uhci_reset_std_chain#2@0: xfer=0x3e08e00 len 8 isread 128 toggle 1
 1487162397.416517480 uhci_device_ctrl_start#2@0: --- dump start ---
 1487162397.416526929 uhci_device_ctrl_start#2@0: before transfer
 1487162397.416544538 uhci_dump_td#32@0: called!
 1487162397.416559570 uhci_dump_td#32@0: TD(0xd24770) at 0x00d24770
 1487162397.416575461 uhci_dump_td#32@0:    link=0x00d24740 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487162397.416590064 uhci_dump_td#32@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.416608103 uhci_dump_td#32@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.416620987 uhci_dump_td#32@0: ios     =0 ls      =1 spd     =0
 1487162397.416633013 uhci_dump_td#32@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.416648045 uhci_dump_td#32@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.416663937 uhci_dump_td#33@0: called!
 1487162397.416671667 uhci_dump_td#33@0: TD(0xd24740) at 0x00d24740
 1487162397.416679398 uhci_dump_td#33@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487162397.416685841 uhci_dump_td#33@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.416693571 uhci_dump_td#33@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.416701302 uhci_dump_td#33@0: ios     =0 ls      =1 spd     =1
 1487162397.416709892 uhci_dump_td#33@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.416715476 uhci_dump_td#33@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162397.416725783 uhci_dump_td#34@0: called!
 1487162397.416733944 uhci_dump_td#34@0: TD(0xd247a0) at 0x00d247a0
 1487162397.416742104 uhci_dump_td#34@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487162397.416748546 uhci_dump_td#34@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.416757995 uhci_dump_td#34@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.416767014 uhci_dump_td#34@0: ios     =0 ls      =1 spd     =0
 1487162397.416776034 uhci_dump_td#34@0: errcnt  =3 actlen  =1024 pid=e1
 1487162397.416781617 uhci_dump_td#34@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.416794072 uhci_device_ctrl_start#2@0: --- dump end ---
 1487162397.416815976 uhci_add_ls_ctrl#2@0: called!
 1487162397.416828002 uhci_add_ls_ctrl#2@0: sqh 0xd22710
 1487162397.416851195 uhci_device_ctrl_start#2@0: --- dump start ---
 1487162397.416862791 uhci_device_ctrl_start#2@0: follow from [0]
 1487162397.416874387 uhci_dump_td#35@0: called!
 1487162397.416886413 uhci_dump_td#35@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487162397.416892855 uhci_dump_td#35@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487162397.416901875 uhci_dump_td#35@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.416909606 uhci_dump_td#35@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.416917766 uhci_dump_td#35@0: ios     =1 ls      =0 spd     =0
 1487162397.416923779 uhci_dump_td#35@0: errcnt  =0 actlen  =1 pid=00
 1487162397.416932798 uhci_dump_td#35@0: addr=0  endpt=0  D=0  maxlen=1,
 1487162397.416947401 uhci_dump_qh#9@0: called!
 1487162397.416961574 uhci_dump_qh#9@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.416974029 uhci_dump_qh#10@0: called!
 1487162397.416983049 uhci_dump_qh#10@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.416994215 uhci_dump_qh#11@0: called!
 1487162397.417001946 uhci_dump_qh#11@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487162397.417009247 uhci_dump_qh#12@0: called!
 1487162397.417019555 uhci_dump_qh#12@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162397.417029004 uhci_dump_qh#13@0: called!
 1487162397.417037594 uhci_dump_qh#13@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487162397.417045754 uhci_dump_qh#14@0: called!
 1487162397.417056491 uhci_dump_qh#14@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487162397.417065940 uhci_dump_qh#15@0: called!
 1487162397.417075389 uhci_dump_qh#15@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487162397.417085697 uhci_device_ctrl_start#2@0: Enqueued QH:
 1487162397.417096434 uhci_dump_qh#16@0: called!
 1487162397.417105453 uhci_dump_qh#16@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162397.417115332 uhci_dump_td#36@0: called!
 1487162397.417121774 uhci_dump_td#36@0: TD(0xd24770) at 0x00d24770
 1487162397.417130364 uhci_dump_td#36@0:    link=0x00d24740 status=0x1c8003ff token=0x00e0002d buffer=0x00d5dec0
 1487162397.417138095 uhci_dump_td#36@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.417146255 uhci_dump_td#36@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.417152268 uhci_dump_td#36@0: ios     =0 ls      =1 spd     =0
 1487162397.417161287 uhci_dump_td#36@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.417170307 uhci_dump_td#36@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.417180614 uhci_dump_td#37@0: called!
 1487162397.417187057 uhci_dump_td#37@0: TD(0xd24740) at 0x00d24740
 1487162397.417194358 uhci_dump_td#37@0:    link=0x00d247a0 status=0x3c8003ff token=0x00e80069 buffer=0x00d5de80
 1487162397.417202089 uhci_dump_td#37@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.417210249 uhci_dump_td#37@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.417216692 uhci_dump_td#37@0: ios     =0 ls      =1 spd     =1
 1487162397.417226570 uhci_dump_td#37@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.417234730 uhci_dump_td#37@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162397.417245468 uhci_dump_td#38@0: called!
 1487162397.417251910 uhci_dump_td#38@0: TD(0xd247a0) at 0x00d247a0
 1487162397.417260929 uhci_dump_td#38@0:    link=0x00000001 status=0x1d8003ff token=0xffe800e1 buffer=0x00000000
 1487162397.417269090 uhci_dump_td#38@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.417277250 uhci_dump_td#38@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.417283692 uhci_dump_td#38@0: ios     =0 ls      =1 spd     =0
 1487162397.417293141 uhci_dump_td#38@0: errcnt  =3 actlen  =1024 pid=e1
 1487162397.417301731 uhci_dump_td#38@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.417312898 uhci_device_ctrl_start#2@0: --- dump end ---
 1487162397.417345539 usbd_transfer#7@0: <- done transfer 0x3e08e00, err = 1
 1487162397.417361001 usbd_transfer#7@0: <- sleeping on xfer 0x3e08e00
 1487162397.432805073 uhci_intr#3@0: called!
 1487162397.432832561 uhci_intr1#3@0: called!
 1487162397.432841150 uhci_intr1#3@0: sc 0x3e32008
 1487162397.432858330 uhci_dumpregs#3@0: called!
 1487162397.432869067 uhci_dumpregs#3@0: cmd =0081  sts    =0001  intr   =000f  frnum =0519
 1487162397.432888824 uhci_dumpregs#3@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487162397.432924901 usb_schedsoftintr#3@0: called!
 1487162397.432938215 usb_schedsoftintr#3@0: polling=0
 1487162397.432968709 uhci_intr1#3@0: sc 0x3e32008 done
 1487162397.433070499 uhci_softintr#3@0: called!
 1487162397.433079948 uhci_softintr#3@0: sc 0x3e32008
 1487162397.433102711 uhci_check_intr#2@0: called!
 1487162397.433113877 uhci_check_intr#2@0: ux 0x3e08e00
 1487162397.433136640 uhci_check_intr#2@0: ux=0x3e08e00 done
 1487162397.433168852 uhci_idone#2@0: called!
 1487162397.433180449 uhci_idone#2@0: ux=0x3e08e00
 1487162397.433193763 uhci_idone#2@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x39f9d88 ready
 1487162397.433204500 uhci_idone#2@0: --- dump start ---
 1487162397.433218244 uhci_dump_td#39@0: called!
 1487162397.433226834 uhci_dump_td#39@0: TD(0xd24770) at 0x00d24770
 1487162397.433235853 uhci_dump_td#39@0:    link=0x00d24740 status=0x1c000007 token=0x00e0002d buffer=0x00d5dec0
 1487162397.433248738 uhci_dump_td#39@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.433267206 uhci_dump_td#39@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.433277943 uhci_dump_td#39@0: ios     =0 ls      =1 spd     =0
 1487162397.433286103 uhci_dump_td#39@0: errcnt  =3 actlen  =8 pid=2d
 1487162397.433297700 uhci_dump_td#39@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.433311873 uhci_dump_td#40@0: called!
 1487162397.433320463 uhci_dump_td#40@0: TD(0xd24740) at 0x00d24740
 1487162397.433328193 uhci_dump_td#40@0:    link=0x00d247a0 status=0x1c000007 token=0x00e80069 buffer=0x00d5de80
 1487162397.433336354 uhci_dump_td#40@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.433342796 uhci_dump_td#40@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.433352245 uhci_dump_td#40@0: ios     =0 ls      =1 spd     =0
 1487162397.433360405 uhci_dump_td#40@0: errcnt  =3 actlen  =8 pid=69
 1487162397.433368566 uhci_dump_td#40@0: addr=0  endpt=0  D=1  maxlen=8,
 1487162397.433376726 uhci_dump_td#41@0: called!
 1487162397.433386175 uhci_dump_td#41@0: TD(0xd247a0) at 0x00d247a0
 1487162397.433394335 uhci_dump_td#41@0:    link=0x00000001 status=0x1d0007ff token=0xffe800e1 buffer=0x00000000
 1487162397.433402495 uhci_dump_td#41@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.433408508 uhci_dump_td#41@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487162397.433417957 uhci_dump_td#41@0: ios     =0 ls      =1 spd     =0
 1487162397.433425688 uhci_dump_td#41@0: errcnt  =3 actlen  =0 pid=e1
 1487162397.433433848 uhci_dump_td#41@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.433445015 uhci_idone#2@0: --- dump end ---
 1487162397.433460906 uhci_idone#2@0: actlen=8, status=0x0
 1487162397.433479804 uhci_idone#2@0: ux=0x3e08e00 done
 1487162397.433494407 uhci_softintr#3@0: ux 0x3e08e00
 1487162397.433510298 usb_transfer_complete#9@0: called!
 1487162397.433522753 usb_transfer_complete#9@0: pipe = 0x39f9d88 xfer = 0x3e08e00 status = 0 actlen = 8
 1487162397.433537785 usb_transfer_complete#9@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.433551099 usb_transfer_complete#9@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487162397.433569138 uhci_device_ctrl_done#2@0: called!
 1487162397.433600920 uhci_remove_ls_ctrl#2@0: called!
 1487162397.433615094 uhci_remove_ls_ctrl#2@0: sqh 0xd22710
 1487162397.433637427 uhci_find_prev_qh#2@0: called!
 1487162397.433654177 uhci_find_prev_qh#2@0: pqh=0xd20740 sqh=0xd22710
 1487162397.433713018 uhci_device_ctrl_done#2@0: length=8
 1487162397.433732345 usb_transfer_complete#9@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.433746088 usb_transfer_complete#9@0: <- done xfer 0x3e08e00, wakeup
 1487162397.433849596 usbd_start_next#9@0: called!
 1487162397.433864628 usbd_start_next#9@0: pipe = 0x39f9d88, xfer = 0x0
 1487162397.434040719 uhci_free_stds#2@0: called!
 1487162397.434052316 uhci_free_stds#2@0: ux=0x3e08e00
 1487162397.434133919 usbd_free_xfer#7@0: called!
 1487162397.434151528 usbd_free_xfer#7@0: 0x3e08e00
 1487162397.434179874 usb_freemem#4@0: called!
 1487162397.434199631 usb_freemem#4@0: frag=0xd5de80
 1487162397.434280805 usbd_reset_port#2@0: called!
 1487162397.434303138 usbd_do_request_flags#8@0: called!
 1487162397.434322465 usbd_alloc_xfer#8@0: called!
 1487162397.434374004 usbd_alloc_xfer#8@0: returns 0x3e08e00
 1487162397.434408364 usbd_transfer#8@0: called!
 1487162397.434420389 usbd_transfer#8@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162397.434436281 usbd_dump_queue#8@0: called!
 1487162397.434447018 usbd_dump_queue#8@0: pipe = 0x3e2d6c8
 1487162397.434466345 usb_insert_transfer#8@0: called!
 1487162397.434477941 usb_insert_transfer#8@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162397.434495980 usb_insert_transfer#8@0: <- done xfer 0x3e08e00, err 0
 1487162397.434514878 roothub_ctrl_start#6@0: called!
 1487162397.434525615 roothub_ctrl_start#6@0: type=0x23 request=0x3
 1487162397.434555679 uhci_roothub_ctrl#6@0: called!
 1487162397.434565987 uhci_roothub_ctrl#6@0: type=0x23 request=03
 1487162397.434601635 uhci_portreset#2@0: called!
 1487162397.544539775 uhci_poll_hub#9@0: called!
 1487162397.544591743 usb_transfer_complete#10@0: called!
 1487162397.544602910 usb_transfer_complete#10@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487162397.544617083 usb_transfer_complete#10@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487162397.544632545 usb_transfer_complete#10@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487162397.544649724 usb_transfer_complete#10@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487162397.544688808 usbd_start_next#10@0: called!
 1487162397.544703411 usbd_start_next#10@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487162397.544727892 uhci_root_intr_start#3@0: called!
 1487162397.544747219 uhci_root_intr_start#3@0: xfer=0x3e08ee0 len=1 flags=132
 1487162397.1532553258 uhci_portreset#2@0: uhci port 1 reset, status0 = 0x038a
 1487162397.1533008948 uhci_portreset#2@0: uhci port 1 reset, status1 = 0x01ab
 1487162397.1618441611 uhci_poll_hub#10@0: called!
 1487162397.1618474252 usb_transfer_complete#11@0: called!
 1487162397.1618485848 usb_transfer_complete#11@0: pipe = 0x3e2d448 xfer = 0x3e08ee0 status = 0 actlen = 1
 1487162397.1618501739 usb_transfer_complete#11@0: xfer 0x3e08ee0: repeat 1 new head = 0x3e08ee0
 1487162397.1618513336 usb_transfer_complete#11@0: xfer 0x3e08ee0 doing done 0x2a6a14
 1487162397.1618533092 usb_transfer_complete#11@0: xfer 0x3e08ee0 doing callback 0x1c5944 status 0
 1487162397.1618562727 usbd_start_next#11@0: called!
 1487162397.1618576471 usbd_start_next#11@0: pipe = 0x3e2d448, xfer = 0x3e08ee0
 1487162397.1618591503 uhci_root_intr_start#4@0: called!
 1487162397.1618609112 uhci_root_intr_start#4@0: xfer=0x3e08ee0 len=1 flags=132
 1487162397.1790228625 uhci_portreset#2@0: uhci port 1 iteration 9, status = 0x01af
 1487162397.2047906569 uhci_portreset#2@0: uhci port 1 iteration 8, status = 0x01a5
 1487162397.2047919024 uhci_portreset#2@0: uhci port 1 reset, status2 = 0x01a5
 1487162397.2047952095 roothub_ctrl_start#6@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162397.2047963691 roothub_ctrl_start#6@0: xfer 0x3e08e00 err 0
 1487162397.2047986025 usb_transfer_complete#12@0: called!
 1487162397.2047995044 usb_transfer_complete#12@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162397.2048010506 usb_transfer_complete#12@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.2048029833 usb_transfer_complete#12@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162397.2048046583 usb_transfer_complete#12@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.2048058609 usb_transfer_complete#12@0: <- done xfer 0x3e08e00, wakeup
 1487162397.2048080942 usbd_start_next#12@0: called!
 1487162397.2048094686 usbd_start_next#12@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162397.2048118308 usbd_transfer#8@0: <- done transfer 0x3e08e00, err = 0
 1487162397.2048129475 usbd_transfer#8@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162397.2048160827 usbd_free_xfer#8@0: called!
 1487162397.2048171135 usbd_free_xfer#8@0: 0x3e08e00
 1487162397.2048244149 usbd_reset_port#2@0: port 1 reset done, error=0
 1487162397.-1989214423 usbd_get_port_status#3@0: called!
 1487162397.-1989198532 usbd_get_port_status#3@0: dev 0x3e27298 port 1
 1487162397.-1989174051 usbd_do_request_flags#9@0: called!
 1487162397.-1989145704 usbd_alloc_xfer#9@0: called!
 1487162397.-1989071402 usbd_alloc_xfer#9@0: returns 0x3e08e00
 1487162397.-1989033607 usb_allocmem_flags#6@0: called!
 1487162397.-1989001395 usb_allocmem_flags#6@0: use frag=0xd5de80 size=4
 1487162397.-1988950286 usbd_transfer#9@0: called!
 1487162397.-1988941266 usbd_transfer#9@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162397.-1988922798 usbd_dump_queue#9@0: called!
 1487162397.-1988912491 usbd_dump_queue#9@0: pipe = 0x3e2d6c8
 1487162397.-1988885003 usb_insert_transfer#9@0: called!
 1487162397.-1988875984 usb_insert_transfer#9@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162397.-1988858375 usb_insert_transfer#9@0: <- done xfer 0x3e08e00, err 0
 1487162397.-1988831746 roothub_ctrl_start#7@0: called!
 1487162397.-1988819720 roothub_ctrl_start#7@0: type=0xa3 request= 0
 1487162397.-1988784073 uhci_roothub_ctrl#7@0: called!
 1487162397.-1988772906 uhci_roothub_ctrl#7@0: type=0xa3 request=00
 1487162397.-1988746277 uhci_roothub_ctrl#7@0: returning 4
 1487162397.-1988731675 roothub_ctrl_start#7@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487162397.-1988721367 roothub_ctrl_start#7@0: xfer 0x3e08e00 err 0
 1487162397.-1988697316 usb_transfer_complete#13@0: called!
 1487162397.-1988687008 usb_transfer_complete#13@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487162397.-1988670687 usb_transfer_complete#13@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-1988656084 usb_transfer_complete#13@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162397.-1988632892 usb_transfer_complete#13@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.-1988620007 usb_transfer_complete#13@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-1988596815 usbd_start_next#13@0: called!
 1487162397.-1988584359 usbd_start_next#13@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162397.-1988565891 usbd_transfer#9@0: <- done transfer 0x3e08e00, err = 0
 1487162397.-1988553436 usbd_transfer#9@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162397.-1988531532 usbd_free_xfer#9@0: called!
 1487162397.-1988522942 usbd_free_xfer#9@0: 0x3e08e00
 1487162397.-1988499320 usb_freemem#5@0: called!
 1487162397.-1988478275 usb_freemem#5@0: frag=0xd5de80
 1487162397.-1988390659 usbd_clear_port_feature#3@0: called!
 1487162397.-1988381210 usbd_clear_port_feature#3@0: dev 0x3e27298 port 1 sel 20
 1487162397.-1988364889 usbd_do_request_flags#10@0: called!
 1487162397.-1988353723 usbd_alloc_xfer#10@0: called!
 1487162397.-1988326235 usbd_alloc_xfer#10@0: returns 0x3e08e00
 1487162397.-1988313350 usbd_transfer#10@0: called!
 1487162397.-1988303902 usbd_transfer#10@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162397.-1988290587 usbd_dump_queue#10@0: called!
 1487162397.-1988279850 usbd_dump_queue#10@0: pipe = 0x3e2d6c8
 1487162397.-1988267824 usb_insert_transfer#10@0: called!
 1487162397.-1988258805 usb_insert_transfer#10@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162397.-1988248497 usb_insert_transfer#10@0: <- done xfer 0x3e08e00, err 0
 1487162397.-1988233895 roothub_ctrl_start#8@0: called!
 1487162397.-1988223587 roothub_ctrl_start#8@0: type=0x23 request=0x1
 1487162397.-1988208555 uhci_roothub_ctrl#8@0: called!
 1487162397.-1988200394 uhci_roothub_ctrl#8@0: type=0x23 request=01
 1487162397.-1988184933 uhci_roothub_ctrl#8@0: UR_CLEAR_PORT_FEATURE port=1 feature=20
 1487162397.-1988168612 uhci_roothub_ctrl#8@0: returning 0
 1487162397.-1988157016 roothub_ctrl_start#8@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162397.-1988148855 roothub_ctrl_start#8@0: xfer 0x3e08e00 err 0
 1487162397.-1988135541 usb_transfer_complete#14@0: called!
 1487162397.-1988125663 usb_transfer_complete#14@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162397.-1988112778 usb_transfer_complete#14@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-1988101611 usb_transfer_complete#14@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162397.-1988090874 usb_transfer_complete#14@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.-1988082714 usb_transfer_complete#14@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-1988067252 usbd_start_next#14@0: called!
 1487162397.-1988055656 usbd_start_next#14@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162397.-1988037617 usbd_transfer#10@0: <- done transfer 0x3e08e00, err = 0
 1487162397.-1988029886 usbd_transfer#10@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162397.-1988017860 usbd_free_xfer#10@0: called!
 1487162397.-1988006694 usbd_free_xfer#10@0: 0x3e08e00
 1487162397.-1602956275 uhci_poll_hub#11@0: called!
 1487162397.-872701051 usbd_new_device#1@0: adding unit addr=2, rev=200, class=0, subclass=0
 1487162397.-872679577 usbd_new_device#1@0: protocol=0, maxpacket=8, len=18, speed=1
 1487162397.-872625890 usbd_ar_pipe#1@0: called!
 1487162397.-872606134 usbd_ar_pipe#1@0: pipe = 0x39f9d88
 1487162397.-872588095 usbd_dump_queue#11@0: called!
 1487162397.-872578217 usbd_dump_queue#11@0: pipe = 0x39f9d88
 1487162397.-872494466 usb_rem_task#1@0: called!
 1487162397.-872418446 usbd_setup_pipe_flags#2@0: called!
 1487162397.-872368625 usbd_setup_pipe_flags#2@0: dev=0x375d860 addr=0 iface=0x0 ep=0x375d884 pipe=0xfdc054cc
 1487162397.-872348439 uhci_open#2@0: called!
 1487162397.-872331259 uhci_open#2@0: pipe=0x39f9d88, addr=0, endpt=0 (1)
 1487162397.-872302913 uhci_alloc_sqh#2@0: called!
 1487162397.-872280579 uhci_alloc_std#12@0: called!
 1487162397.-872267695 uhci_alloc_std#13@0: called!
 1487162397.-872250515 usb_allocmem_flags#7@0: called!
 1487162397.-872221739 usb_allocmem_flags#7@0: use frag=0xd5de80 size=8
 1487162397.-872199835 usbd_setup_pipe_flags#2@0: pipe=0x39f9d88
 1487162397.-872174495 usbd_new_device#1@0: setting device address=2
 1487162397.-872146149 usbd_set_address#1@0: called!
 1487162397.-872130687 usbd_set_address#1@0: dev 0x375d860 addr 2
 1487162397.-872108353 usbd_do_request_flags#11@0: called!
 1487162397.-872094610 usbd_alloc_xfer#11@0: called!
 1487162397.-872049943 usbd_alloc_xfer#11@0: returns 0x3e08e00
 1487162397.-872025891 uhci_device_ctrl_init#3@0: called!
 1487162397.-872015154 uhci_device_ctrl_init#3@0: xfer=0x3e08e00 len=0, addr=0, endpt=0
 1487162397.-871986807 usbd_transfer#11@0: called!
 1487162397.-871976070 usbd_transfer#11@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x39f9d88, running = 0
 1487162397.-871964474 usbd_dump_queue#12@0: called!
 1487162397.-871958031 usbd_dump_queue#12@0: pipe = 0x39f9d88
 1487162397.-871936557 usb_insert_transfer#11@0: called!
 1487162397.-871925390 usb_insert_transfer#11@0: xfer = 0x3e08e00 pipe = 0x39f9d88 running = 0 timeout = 5000
 1487162397.-871909069 usb_insert_transfer#11@0: <- done xfer 0x3e08e00, err 0
 1487162397.-871885447 uhci_device_ctrl_start#3@0: called!
 1487162397.-871872133 uhci_device_ctrl_start#3@0: type=0x00, request=0x05, wValue=0x0002, wIndex=0x0000
 1487162397.-871854954 uhci_device_ctrl_start#3@0: len=0, addr=0, endpt=0
 1487162397.-871798261 uhci_device_ctrl_start#3@0: --- dump start ---
 1487162397.-871785376 uhci_device_ctrl_start#3@0: before transfer
 1487162397.-871763901 uhci_dump_td#42@0: called!
 1487162397.-871749299 uhci_dump_td#42@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-871735126 uhci_dump_td#42@0:    link=0x00d24770 status=0x1c8003ff token=0x00e0002d buffer=0x00d5de80
 1487162397.-871720523 uhci_dump_td#42@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-871700766 uhci_dump_td#42@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-871684446 uhci_dump_td#42@0: ios     =0 ls      =1 spd     =0
 1487162397.-871673279 uhci_dump_td#42@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.-871657817 uhci_dump_td#42@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.-871641926 uhci_dump_td#43@0: called!
 1487162397.-871633336 uhci_dump_td#43@0: TD(0xd24770) at 0x00d24770
 1487162397.-871624746 uhci_dump_td#43@0:    link=0x00000001 status=0x1d8003ff token=0xffe80069 buffer=0x00000000
 1487162397.-871618733 uhci_dump_td#43@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-871610144 uhci_dump_td#43@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.-871602413 uhci_dump_td#43@0: ios     =0 ls      =1 spd     =0
 1487162397.-871594252 uhci_dump_td#43@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-871588669 uhci_dump_td#43@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.-871575784 uhci_device_ctrl_start#3@0: --- dump end ---
 1487162397.-871544002 uhci_add_ls_ctrl#3@0: called!
 1487162397.-871533694 uhci_add_ls_ctrl#3@0: sqh 0xd22710
 1487162397.-871503630 uhci_device_ctrl_start#3@0: --- dump start ---
 1487162397.-871486021 uhci_device_ctrl_start#3@0: follow from [0]
 1487162397.-871472277 uhci_dump_td#44@0: called!
 1487162397.-871460251 uhci_dump_td#44@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487162397.-871453379 uhci_dump_td#44@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487162397.-871444789 uhci_dump_td#44@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-871436629 uhci_dump_td#44@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-871427180 uhci_dump_td#44@0: ios     =1 ls      =0 spd     =0
 1487162397.-871419879 uhci_dump_td#44@0: errcnt  =0 actlen  =1 pid=00
 1487162397.-871409571 uhci_dump_td#44@0: addr=0  endpt=0  D=0  maxlen=1,
 1487162397.-871390244 uhci_dump_qh#17@0: called!
 1487162397.-871375641 uhci_dump_qh#17@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.-871363616 uhci_dump_qh#18@0: called!
 1487162397.-871355455 uhci_dump_qh#18@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.-871344289 uhci_dump_qh#19@0: called!
 1487162397.-871336128 uhci_dump_qh#19@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487162397.-871328397 uhci_dump_qh#20@0: called!
 1487162397.-871319808 uhci_dump_qh#20@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d247a0
 1487162397.-871310359 uhci_dump_qh#21@0: called!
 1487162397.-871300910 uhci_dump_qh#21@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487162397.-871292320 uhci_dump_qh#22@0: called!
 1487162397.-871280294 uhci_dump_qh#22@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487162397.-871270846 uhci_dump_qh#23@0: called!
 1487162397.-871261397 uhci_dump_qh#23@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487162397.-871251948 uhci_device_ctrl_start#3@0: Enqueued QH:
 1487162397.-871242499 uhci_dump_qh#24@0: called!
 1487162397.-871234339 uhci_dump_qh#24@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d247a0
 1487162397.-871224890 uhci_dump_td#45@0: called!
 1487162397.-871217159 uhci_dump_td#45@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-871206851 uhci_dump_td#45@0:    link=0x00d24770 status=0x1c8003ff token=0x00e0002d buffer=0x00d5de80
 1487162397.-871198691 uhci_dump_td#45@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-871190960 uhci_dump_td#45@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-871184088 uhci_dump_td#45@0: ios     =0 ls      =1 spd     =0
 1487162397.-871175069 uhci_dump_td#45@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.-871166909 uhci_dump_td#45@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.-871156601 uhci_dump_td#46@0: called!
 1487162397.-871148870 uhci_dump_td#46@0: TD(0xd24770) at 0x00d24770
 1487162397.-871139421 uhci_dump_td#46@0:    link=0x00000001 status=0x1d8003ff token=0xffe80069 buffer=0x00000000
 1487162397.-871130402 uhci_dump_td#46@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-871122671 uhci_dump_td#46@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.-871115799 uhci_dump_td#46@0: ios     =0 ls      =1 spd     =0
 1487162397.-871106780 uhci_dump_td#46@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-871098620 uhci_dump_td#46@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.-871087882 uhci_device_ctrl_start#3@0: --- dump end ---
 1487162397.-871042356 usbd_transfer#11@0: <- done transfer 0x3e08e00, err = 1
 1487162397.-871026036 usbd_transfer#11@0: <- sleeping on xfer 0x3e08e00
 1487162397.-859968356 uhci_intr#4@0: called!
 1487162397.-859939151 uhci_intr1#4@0: called!
 1487162397.-859930132 uhci_intr1#4@0: sc 0x3e32008
 1487162397.-859912522 uhci_dumpregs#4@0: called!
 1487162397.-859901356 uhci_dumpregs#4@0: cmd =0081  sts    =0001  intr   =000f  frnum =07d4
 1487162397.-859881170 uhci_dumpregs#4@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487162397.-859842515 usb_schedsoftintr#4@0: called!
 1487162397.-859829201 usb_schedsoftintr#4@0: polling=0
 1487162397.-859794412 uhci_intr1#4@0: sc 0x3e32008 done
 1487162397.-859680597 uhci_softintr#4@0: called!
 1487162397.-859668571 uhci_softintr#4@0: sc 0x3e32008
 1487162397.-859642802 uhci_check_intr#3@0: called!
 1487162397.-859632065 uhci_check_intr#3@0: ux 0x3e08e00
 1487162397.-859609302 uhci_check_intr#3@0: ux=0x3e08e00 done
 1487162397.-859571077 uhci_idone#3@0: called!
 1487162397.-859559910 uhci_idone#3@0: ux=0x3e08e00
 1487162397.-859546166 uhci_idone#3@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x39f9d88 ready
 1487162397.-859535429 uhci_idone#3@0: --- dump start ---
 1487162397.-859521256 uhci_dump_td#47@0: called!
 1487162397.-859510089 uhci_dump_td#47@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-859498063 uhci_dump_td#47@0:    link=0x00d24770 status=0x1c000007 token=0x00e0002d buffer=0x00d5de80
 1487162397.-859484749 uhci_dump_td#47@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-859467140 uhci_dump_td#47@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-859454255 uhci_dump_td#47@0: ios     =0 ls      =1 spd     =0
 1487162397.-859446525 uhci_dump_td#47@0: errcnt  =3 actlen  =8 pid=2d
 1487162397.-859434499 uhci_dump_td#47@0: addr=0  endpt=0  D=0  maxlen=8,
 1487162397.-859421185 uhci_dump_td#48@0: called!
 1487162397.-859412595 uhci_dump_td#48@0: TD(0xd24770) at 0x00d24770
 1487162397.-859405293 uhci_dump_td#48@0:    link=0x00000001 status=0x1d0007ff token=0xffe80069 buffer=0x00000000
 1487162397.-859396704 uhci_dump_td#48@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-859390261 uhci_dump_td#48@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487162397.-859380812 uhci_dump_td#48@0: ios     =0 ls      =1 spd     =0
 1487162397.-859372652 uhci_dump_td#48@0: errcnt  =3 actlen  =0 pid=69
 1487162397.-859364492 uhci_dump_td#48@0: addr=0  endpt=0  D=1  maxlen=2048,
 1487162397.-859354613 uhci_idone#3@0: --- dump end ---
 1487162397.-859339152 uhci_idone#3@0: actlen=0, status=0x0
 1487162397.-859321113 uhci_idone#3@0: ux=0x3e08e00 done
 1487162397.-859306510 uhci_softintr#4@0: ux 0x3e08e00
 1487162397.-859291478 usb_transfer_complete#15@0: called!
 1487162397.-859280311 usb_transfer_complete#15@0: pipe = 0x39f9d88 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162397.-859263561 usb_transfer_complete#15@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-859248959 usb_transfer_complete#15@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487162397.-859221901 uhci_device_ctrl_done#3@0: called!
 1487162397.-859191407 uhci_remove_ls_ctrl#3@0: called!
 1487162397.-859174657 uhci_remove_ls_ctrl#3@0: sqh 0xd22710
 1487162397.-859150176 uhci_find_prev_qh#3@0: called!
 1487162397.-859134714 uhci_find_prev_qh#3@0: pqh=0xd20740 sqh=0xd22710
 1487162397.-859074156 uhci_device_ctrl_done#3@0: length=0
 1487162397.-859057835 usb_transfer_complete#15@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.-859043662 usb_transfer_complete#15@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-858946597 usbd_start_next#15@0: called!
 1487162397.-858932424 usbd_start_next#15@0: pipe = 0x39f9d88, xfer = 0x0
 1487162397.-858745165 uhci_free_stds#3@0: called!
 1487162397.-858734858 uhci_free_stds#3@0: ux=0x3e08e00
 1487162397.-858708659 usbd_free_xfer#11@0: called!
 1487162397.-858697062 usbd_free_xfer#11@0: 0x3e08e00
 1487162397.-786753858 usbd_ar_pipe#2@0: called!
 1487162397.-786739255 usbd_ar_pipe#2@0: pipe = 0x39f9d88
 1487162397.-786724223 usbd_dump_queue#13@0: called!
 1487162397.-786713056 usbd_dump_queue#13@0: pipe = 0x39f9d88
 1487162397.-786667101 usb_rem_task#2@0: called!
 1487162397.-786593228 usbd_setup_pipe_flags#3@0: called!
 1487162397.-786532670 usbd_setup_pipe_flags#3@0: dev=0x375d860 addr=2 iface=0x0 ep=0x375d884 pipe=0xfdc05f40
 1487162397.-786513772 uhci_open#3@0: called!
 1487162397.-786496593 uhci_open#3@0: pipe=0x39f9d88, addr=2, endpt=0 (1)
 1487162397.-786475118 uhci_alloc_sqh#3@0: called!
 1487162397.-786457079 uhci_alloc_std#14@0: called!
 1487162397.-786440759 uhci_alloc_std#15@0: called!
 1487162397.-786421432 usb_allocmem_flags#8@0: called!
 1487162397.-786391367 usb_allocmem_flags#8@0: use frag=0xd5de40 size=8
 1487162397.-786372470 usbd_setup_pipe_flags#3@0: pipe=0x39f9d88
 1487162397.-786341976 usbd_reload_device_desc#1@0: called!
 1487162397.-786314059 usbd_get_device_desc#1@0: called!
 1487162397.-786279700 usbd_get_desc#1@0: called!
 1487162397.-786263808 usbd_get_desc#1@0: type=1, index=0, len=18
 1487162397.-786236750 usbd_do_request_flags#12@0: called!
 1487162397.-786222148 usbd_alloc_xfer#12@0: called!
 1487162397.-786180058 usbd_alloc_xfer#12@0: returns 0x3e08e00
 1487162397.-786159871 usb_allocmem_flags#9@0: called!
 1487162397.-786143121 usb_allocmem_flags#9@0: use frag=0xd5de00 size=18
 1487162397.-786123794 uhci_device_ctrl_init#4@0: called!
 1487162397.-786113486 uhci_device_ctrl_init#4@0: xfer=0x3e08e00 len=18, addr=2, endpt=0
 1487162397.-786095877 uhci_alloc_std_chain#3@0: called!
 1487162397.-786085140 uhci_alloc_std_chain#3@0: xfer=0x3e08e00 pipe=0x39f9d88
 1487162397.-786071396 uhci_alloc_std_chain#3@0: maxp=8 ntd=3
 1487162397.-786024582 uhci_alloc_std#16@0: called!
 1487162397.-786011697 uhci_alloc_std#17@0: called!
 1487162397.-785996235 uhci_alloc_std#18@0: called!
 1487162397.-785959299 usbd_transfer#12@0: called!
 1487162397.-785948132 usbd_transfer#12@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x39f9d88, running = 0
 1487162397.-785939543 usbd_dump_queue#14@0: called!
 1487162397.-785930953 usbd_dump_queue#14@0: pipe = 0x39f9d88
 1487162397.-785909478 usb_insert_transfer#12@0: called!
 1487162397.-785898741 usb_insert_transfer#12@0: xfer = 0x3e08e00 pipe = 0x39f9d88 running = 0 timeout = 5000
 1487162397.-785886286 usb_insert_transfer#12@0: <- done xfer 0x3e08e00, err 0
 1487162397.-785864382 uhci_device_ctrl_start#4@0: called!
 1487162397.-785849779 uhci_device_ctrl_start#4@0: type=0x80, request=0x06, wValue=0x0100, wIndex=0x0000
 1487162397.-785836035 uhci_device_ctrl_start#4@0: len=18, addr=2, endpt=0
 1487162397.-785810695 uhci_reset_std_chain#3@0: called!
 1487162397.-785799958 uhci_reset_std_chain#3@0: xfer=0x3e08e00 len 18 isread 128 toggle 1
 1487162397.-785747130 uhci_device_ctrl_start#4@0: --- dump start ---
 1487162397.-785733816 uhci_device_ctrl_start#4@0: before transfer
 1487162397.-785716207 uhci_dump_td#49@0: called!
 1487162397.-785702034 uhci_dump_td#49@0: TD(0xd24770) at 0x00d24770
 1487162397.-785687431 uhci_dump_td#49@0:    link=0x00d246e0 status=0x1c8003ff token=0x00e0022d buffer=0x00d5de40
 1487162397.-785671970 uhci_dump_td#49@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785654790 uhci_dump_td#49@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-785642335 uhci_dump_td#49@0: ios     =0 ls      =1 spd     =0
 1487162397.-785629879 uhci_dump_td#49@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.-785613129 uhci_dump_td#49@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-785599386 uhci_dump_td#50@0: called!
 1487162397.-785590796 uhci_dump_td#50@0: TD(0xd246e0) at 0x00d246e0
 1487162397.-785582635 uhci_dump_td#50@0:    link=0x00d24714 status=0x1c8003ff token=0x00e80269 buffer=0x00d5de00
 1487162397.-785574475 uhci_dump_td#50@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785568462 uhci_dump_td#50@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-785559013 uhci_dump_td#50@0: ios     =0 ls      =1 spd     =0
 1487162397.-785550853 uhci_dump_td#50@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-785542693 uhci_dump_td#50@0: addr=2  endpt=0  D=1  maxlen=8,
 1487162397.-785534103 uhci_dump_td#51@0: called!
 1487162397.-785524654 uhci_dump_td#51@0: TD(0xd24710) at 0x00d24710
 1487162397.-785515635 uhci_dump_td#51@0:    link=0x00d24744 status=0x1c8003ff token=0x00e00269 buffer=0x00d5de08
 1487162397.-785507045 uhci_dump_td#51@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785500173 uhci_dump_td#51@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-785489865 uhci_dump_td#51@0: ios     =0 ls      =1 spd     =0
 1487162397.-785482134 uhci_dump_td#51@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-785473974 uhci_dump_td#51@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-785465384 uhci_dump_td#52@0: called!
 1487162397.-785456365 uhci_dump_td#52@0: TD(0xd24740) at 0x00d24740
 1487162397.-785448205 uhci_dump_td#52@0:    link=0x00d247a0 status=0x1c8003ff token=0x00280269 buffer=0x00d5de10
 1487162397.-785439185 uhci_dump_td#52@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785432313 uhci_dump_td#52@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-785422006 uhci_dump_td#52@0: ios     =0 ls      =1 spd     =0
 1487162397.-785413845 uhci_dump_td#52@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-785405685 uhci_dump_td#52@0: addr=2  endpt=0  D=1  maxlen=2,
 1487162397.-785397525 uhci_dump_td#53@0: called!
 1487162397.-785388076 uhci_dump_td#53@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-785379486 uhci_dump_td#53@0:    link=0x00000001 status=0x1d8003ff token=0xffe802e1 buffer=0x00000000
 1487162397.-785371326 uhci_dump_td#53@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785364454 uhci_dump_td#53@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.-785354146 uhci_dump_td#53@0: ios     =0 ls      =1 spd     =0
 1487162397.-785345986 uhci_dump_td#53@0: errcnt  =3 actlen  =1024 pid=e1
 1487162397.-785337825 uhci_dump_td#53@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487162397.-785327518 uhci_device_ctrl_start#4@0: --- dump end ---
 1487162397.-785304325 uhci_add_ls_ctrl#4@0: called!
 1487162397.-785293158 uhci_add_ls_ctrl#4@0: sqh 0xd22710
 1487162397.-785270395 uhci_device_ctrl_start#4@0: --- dump start ---
 1487162397.-785258799 uhci_device_ctrl_start#4@0: follow from [0]
 1487162397.-785245485 uhci_dump_td#54@0: called!
 1487162397.-785231312 uhci_dump_td#54@0: TD(0xd1e7a0) at 0x00d1e7a0
 1487162397.-785222722 uhci_dump_td#54@0:    link=0x00d20712 status=0x02000000 token=0x00000000 buffer=0x00000000
 1487162397.-785216279 uhci_dump_td#54@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-785207260 uhci_dump_td#54@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-785199100 uhci_dump_td#54@0: ios     =1 ls      =0 spd     =0
 1487162397.-785190939 uhci_dump_td#54@0: errcnt  =0 actlen  =1 pid=00
 1487162397.-785184927 uhci_dump_td#54@0: addr=0  endpt=0  D=0  maxlen=1,
 1487162397.-785168176 uhci_dump_qh#25@0: called!
 1487162397.-785154862 uhci_dump_qh#25@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.-785141977 uhci_dump_qh#26@0: called!
 1487162397.-785135965 uhci_dump_qh#26@0: QH(0xd20710) at 0x00d20710: hlink=00d20742 elink=00000001
 1487162397.-785123509 uhci_dump_qh#27@0: called!
 1487162397.-785115349 uhci_dump_qh#27@0: QH(0xd20740) at 0x00d20740: hlink=00d22712 elink=00000001
 1487162397.-785105471 uhci_dump_qh#28@0: called!
 1487162397.-785099458 uhci_dump_qh#28@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162397.-785089150 uhci_dump_qh#29@0: called!
 1487162397.-785079272 uhci_dump_qh#29@0: QH(0xd20770) at 0x00d20770: hlink=00d207a2 elink=00000001
 1487162397.-785069823 uhci_dump_qh#30@0: called!
 1487162397.-785061233 uhci_dump_qh#30@0: QH(0xd207a0) at 0x00d207a0: hlink=00d207d2 elink=00000001
 1487162397.-785051784 uhci_dump_qh#31@0: called!
 1487162397.-785044053 uhci_dump_qh#31@0: QH(0xd207d0) at 0x00d207d0: hlink=00000001 elink=00d1e7d0
 1487162397.-785032887 uhci_device_ctrl_start#4@0: Enqueued QH:
 1487162397.-785024297 uhci_dump_qh#32@0: called!
 1487162397.-785015278 uhci_dump_qh#32@0: QH(0xd22710) at 0x00d22710: hlink=00d20772 elink=00d24770
 1487162397.-785005829 uhci_dump_td#55@0: called!
 1487162397.-784997668 uhci_dump_td#55@0: TD(0xd24770) at 0x00d24770
 1487162397.-784991656 uhci_dump_td#55@0:    link=0x00d246e0 status=0x1c8003ff token=0x00e0022d buffer=0x00d5de40
 1487162397.-784982636 uhci_dump_td#55@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-784974476 uhci_dump_td#55@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-784966745 uhci_dump_td#55@0: ios     =0 ls      =1 spd     =0
 1487162397.-784959014 uhci_dump_td#55@0: errcnt  =3 actlen  =1024 pid=2d
 1487162397.-784948706 uhci_dump_td#55@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-784938399 uhci_dump_td#56@0: called!
 1487162397.-784930238 uhci_dump_td#56@0: TD(0xd246e0) at 0x00d246e0
 1487162397.-784923366 uhci_dump_td#56@0:    link=0x00d24714 status=0x1c8003ff token=0x00e80269 buffer=0x00d5de00
 1487162397.-784914347 uhci_dump_td#56@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-784905328 uhci_dump_td#56@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-784896309 uhci_dump_td#56@0: ios     =0 ls      =1 spd     =0
 1487162397.-784889437 uhci_dump_td#56@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-784879129 uhci_dump_td#56@0: addr=2  endpt=0  D=1  maxlen=8,
 1487162397.-784868821 uhci_dump_td#57@0: called!
 1487162397.-784860661 uhci_dump_td#57@0: TD(0xd24710) at 0x00d24710
 1487162397.-784854648 uhci_dump_td#57@0:    link=0x00d24744 status=0x1c8003ff token=0x00e00269 buffer=0x00d5de08
 1487162397.-784845629 uhci_dump_td#57@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-784836609 uhci_dump_td#57@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-784828449 uhci_dump_td#57@0: ios     =0 ls      =1 spd     =0
 1487162397.-784821577 uhci_dump_td#57@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-784812558 uhci_dump_td#57@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-784801820 uhci_dump_td#58@0: called!
 1487162397.-784793660 uhci_dump_td#58@0: TD(0xd24740) at 0x00d24740
 1487162397.-784787218 uhci_dump_td#58@0:    link=0x00d247a0 status=0x1c8003ff token=0x00280269 buffer=0x00d5de10
 1487162397.-784777769 uhci_dump_td#58@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-784769179 uhci_dump_td#58@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-784760589 uhci_dump_td#58@0: ios     =0 ls      =1 spd     =0
 1487162397.-784754576 uhci_dump_td#58@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-784743839 uhci_dump_td#58@0: addr=2  endpt=0  D=1  maxlen=2,
 1487162397.-784733531 uhci_dump_td#59@0: called!
 1487162397.-784725371 uhci_dump_td#59@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-784718929 uhci_dump_td#59@0:    link=0x00000001 status=0x1d8003ff token=0xffe802e1 buffer=0x00000000
 1487162397.-784709480 uhci_dump_td#59@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-784701320 uhci_dump_td#59@0: dbuffer =0 stalled =0 active  =1 ioc     =1
 1487162397.-784692730 uhci_dump_td#59@0: ios     =0 ls      =1 spd     =0
 1487162397.-784685858 uhci_dump_td#59@0: errcnt  =3 actlen  =1024 pid=e1
 1487162397.-784675550 uhci_dump_td#59@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487162397.-784664813 uhci_device_ctrl_start#4@0: --- dump end ---
 1487162397.-784625300 usbd_transfer#12@0: <- done transfer 0x3e08e00, err = 1
 1487162397.-784610697 usbd_transfer#12@0: <- sleeping on xfer 0x3e08e00
 1487162397.-769778220 uhci_intr#5@0: called!
 1487162397.-769749014 uhci_intr1#5@0: called!
 1487162397.-769737418 uhci_intr1#5@0: sc 0x3e32008
 1487162397.-769721527 uhci_dumpregs#5@0: called!
 1487162397.-769710360 uhci_dumpregs#5@0: cmd =0081  sts    =0001  intr   =000f  frnum =07e9
 1487162397.-769689745 uhci_dumpregs#5@0: sof =0040  portsc1=01a5  portsc2=0080  flbase=00d1c000
 1487162397.-769648084 usb_schedsoftintr#5@0: called!
 1487162397.-769635199 usb_schedsoftintr#5@0: polling=0
 1487162397.-769605564 uhci_intr1#5@0: sc 0x3e32008 done
 1487162397.-769498192 uhci_softintr#5@0: called!
 1487162397.-769483589 uhci_softintr#5@0: sc 0x3e32008
 1487162397.-769463832 uhci_check_intr#4@0: called!
 1487162397.-769453524 uhci_check_intr#4@0: ux 0x3e08e00
 1487162397.-769431191 uhci_check_intr#4@0: ux=0x3e08e00 done
 1487162397.-769397261 uhci_idone#4@0: called!
 1487162397.-769388242 uhci_idone#4@0: ux=0x3e08e00
 1487162397.-769374498 uhci_idone#4@0: ux=0x3e08e00, xfer=0x3e08e00, pipe=0x39f9d88 ready
 1487162397.-769363331 uhci_idone#4@0: --- dump start ---
 1487162397.-769347011 uhci_dump_td#60@0: called!
 1487162397.-769340568 uhci_dump_td#60@0: TD(0xd24770) at 0x00d24770
 1487162397.-769328543 uhci_dump_td#60@0:    link=0x00d246e0 status=0x1c000007 token=0x00e0022d buffer=0x00d5de40
 1487162397.-769315658 uhci_dump_td#60@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-769296331 uhci_dump_td#60@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-769286452 uhci_dump_td#60@0: ios     =0 ls      =1 spd     =0
 1487162397.-769277433 uhci_dump_td#60@0: errcnt  =3 actlen  =8 pid=2d
 1487162397.-769264978 uhci_dump_td#60@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-769249087 uhci_dump_td#61@0: called!
 1487162397.-769240497 uhci_dump_td#61@0: TD(0xd246e0) at 0x00d246e0
 1487162397.-769230189 uhci_dump_td#61@0:    link=0x00d24714 status=0x1c000007 token=0x00e80269 buffer=0x00d5de00
 1487162397.-769221170 uhci_dump_td#61@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-769212150 uhci_dump_td#61@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-769205279 uhci_dump_td#61@0: ios     =0 ls      =1 spd     =0
 1487162397.-769196259 uhci_dump_td#61@0: errcnt  =3 actlen  =8 pid=69
 1487162397.-769188099 uhci_dump_td#61@0: addr=2  endpt=0  D=1  maxlen=8,
 1487162397.-769177791 uhci_dump_td#62@0: called!
 1487162397.-769171349 uhci_dump_td#62@0: TD(0xd24710) at 0x00d24710
 1487162397.-769161041 uhci_dump_td#62@0:    link=0x00d24744 status=0x1c000007 token=0x00e00269 buffer=0x00d5de08
 1487162397.-769152881 uhci_dump_td#62@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-769144291 uhci_dump_td#62@0: dbuffer =0 stalled =0 active  =0 ioc     =0
 1487162397.-769137419 uhci_dump_td#62@0: ios     =0 ls      =1 spd     =0
 1487162397.-769128400 uhci_dump_td#62@0: errcnt  =3 actlen  =8 pid=69
 1487162397.-769120239 uhci_dump_td#62@0: addr=2  endpt=0  D=0  maxlen=8,
 1487162397.-769109502 uhci_dump_td#63@0: called!
 1487162397.-769103489 uhci_dump_td#63@0: TD(0xd24740) at 0x00d24740
 1487162397.-769093181 uhci_dump_td#63@0:    link=0x00d247a0 status=0x1c8003ff token=0x00280269 buffer=0x00d5de10
 1487162397.-769085021 uhci_dump_td#63@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-769076431 uhci_dump_td#63@0: dbuffer =0 stalled =0 active  =1 ioc     =0
 1487162397.-769069559 uhci_dump_td#63@0: ios     =0 ls      =1 spd     =0
 1487162397.-769060540 uhci_dump_td#63@0: errcnt  =3 actlen  =1024 pid=69
 1487162397.-769052380 uhci_dump_td#63@0: addr=2  endpt=0  D=1  maxlen=2,
 1487162397.-769041642 uhci_dump_td#64@0: called!
 1487162397.-769035200 uhci_dump_td#64@0: TD(0xd247a0) at 0x00d247a0
 1487162397.-769024892 uhci_dump_td#64@0:    link=0x00000001 status=0x1d0007ff token=0xffe802e1 buffer=0x00000000
 1487162397.-769017161 uhci_dump_td#64@0: bitstuff=0 crcto   =0 nak     =0 babble  =0
 1487162397.-769008572 uhci_dump_td#64@0: dbuffer =0 stalled =0 active  =0 ioc     =1
 1487162397.-769001700 uhci_dump_td#64@0: ios     =0 ls      =1 spd     =0
 1487162397.-768992680 uhci_dump_td#64@0: errcnt  =3 actlen  =0 pid=e1
 1487162397.-768984520 uhci_dump_td#64@0: addr=2  endpt=0  D=1  maxlen=2048,
 1487162397.-768972494 uhci_idone#4@0: --- dump end ---
 1487162397.-768955315 uhci_idone#4@0: actlen=16, status=0x0
 1487162397.-768938565 uhci_idone#4@0: ux=0x3e08e00 done
 1487162397.-768924821 uhci_softintr#5@0: ux 0x3e08e00
 1487162397.-768908071 usb_transfer_complete#16@0: called!
 1487162397.-768899051 usb_transfer_complete#16@0: pipe = 0x39f9d88 xfer = 0x3e08e00 status = 0 actlen = 16
 1487162397.-768882301 usb_transfer_complete#16@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-768861256 usb_transfer_complete#16@0: short transfer 16 < 18
 1487162397.-768847942 usb_transfer_complete#16@0: xfer 0x3e08e00 doing done 0x2a9d30
 1487162397.-768829903 uhci_device_ctrl_done#4@0: called!
 1487162397.-768800698 uhci_remove_ls_ctrl#4@0: called!
 1487162397.-768786525 uhci_remove_ls_ctrl#4@0: sqh 0xd22710
 1487162397.-768763332 uhci_find_prev_qh#4@0: called!
 1487162397.-768746153 uhci_find_prev_qh#4@0: pqh=0xd20740 sqh=0xd22710
 1487162397.-768688171 uhci_device_ctrl_done#4@0: length=16
 1487162397.-768662831 usb_transfer_complete#16@0: xfer 0x3e08e00 doing callback 0x0 status 16
 1487162397.-768649088 usb_transfer_complete#16@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-768552023 usbd_start_next#16@0: called!
 1487162397.-768536990 usbd_start_next#16@0: pipe = 0x39f9d88, xfer = 0x0
 1487162397.-768355316 uhci_free_stds#4@0: called!
 1487162397.-768344149 uhci_free_stds#4@0: ux=0x3e08e00
 1487162397.-768261687 usbd_free_xfer#12@0: called!
 1487162397.-768250090 usbd_free_xfer#12@0: 0x3e08e00
 1487162397.-768227327 usb_freemem#6@0: called!
 1487162397.-768204994 usb_freemem#6@0: frag=0xd5de00
 1487162397.-768167198 usbd_do_request_flags#12@0: returning err = 16
 1487162397.-768121243 usbd_new_device#1@0: addr=2, getting full desc failed, err = 16
 1487162397.-768089890 usbd_remove_device#1@0: called!
 1487162397.-768071422 usbd_remove_device#1@0: dev 0x375d860 up 0x58120
 1487162397.-768049088 usbd_ar_pipe#3@0: called!
 1487162397.-768035345 usbd_ar_pipe#3@0: pipe = 0x39f9d88
 1487162397.-768018595 usbd_dump_queue#15@0: called!
 1487162397.-768006998 usbd_dump_queue#15@0: pipe = 0x39f9d88
 1487162397.-767964908 usb_rem_task#3@0: called!
 1487162397.-723607920 usbd_clear_port_feature#4@0: called!
 1487162397.-723593747 usbd_clear_port_feature#4@0: dev 0x3e27298 port 1 sel 1
 1487162397.-723573991 usbd_do_request_flags#13@0: called!
 1487162397.-723555523 usbd_alloc_xfer#13@0: called!
 1487162397.-723493676 usbd_alloc_xfer#13@0: returns 0x3e08e00
 1487162397.-723452015 usbd_transfer#13@0: called!
 1487162397.-723436983 usbd_transfer#13@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162397.-723422380 usbd_dump_queue#16@0: called!
 1487162397.-723410354 usbd_dump_queue#16@0: pipe = 0x3e2d6c8
 1487162397.-723382867 usb_insert_transfer#13@0: called!
 1487162397.-723366976 usb_insert_transfer#13@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162397.-723349367 usb_insert_transfer#13@0: <- done xfer 0x3e08e00, err 0
 1487162397.-723328322 roothub_ctrl_start#9@0: called!
 1487162397.-723316296 roothub_ctrl_start#9@0: type=0x23 request=0x1
 1487162397.-723283655 uhci_roothub_ctrl#9@0: called!
 1487162397.-723271629 uhci_roothub_ctrl#9@0: type=0x23 request=01
 1487162397.-723247577 uhci_roothub_ctrl#9@0: UR_CLEAR_PORT_FEATURE port=1 feature=1
 1487162397.-723207635 uhci_roothub_ctrl#9@0: returning 0
 1487162397.-723188308 roothub_ctrl_start#9@0: xfer 0x3e08e00 buflen -1 actlen 0
 1487162397.-723179288 roothub_ctrl_start#9@0: xfer 0x3e08e00 err 0
 1487162397.-723160391 usb_transfer_complete#17@0: called!
 1487162397.-723148365 usb_transfer_complete#17@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 0
 1487162397.-723129467 usb_transfer_complete#17@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-723113147 usb_transfer_complete#17@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162397.-723095537 usb_transfer_complete#17@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.-723080505 usb_transfer_complete#17@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-723057313 usbd_start_next#17@0: called!
 1487162397.-723043140 usbd_start_next#17@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162397.-723018659 usbd_transfer#13@0: <- done transfer 0x3e08e00, err = 0
 1487162397.-723001908 usbd_transfer#13@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162397.-722977857 usbd_free_xfer#13@0: called!
 1487162397.-722968838 usbd_free_xfer#13@0: 0x3e08e00
 1487162397.-722748938 usb_needs_explore#2@0: called!
 1487162397.-722677213 usbd_get_port_status#4@0: called!
 1487162397.-722666476 usbd_get_port_status#4@0: dev 0x3e27298 port 1
 1487162397.-722654021 usbd_do_request_flags#14@0: called!
 1487162397.-722641565 usbd_alloc_xfer#14@0: called!
 1487162397.-722610212 usbd_alloc_xfer#14@0: returns 0x3e08e00
 1487162397.-722588308 usb_allocmem_flags#10@0: called!
 1487162397.-722568981 usb_allocmem_flags#10@0: use frag=0xd5de00 size=4
 1487162397.-722544071 usbd_transfer#14@0: called!
 1487162397.-722536340 usbd_transfer#14@0: xfer = 0x3e08e00, flags = 0x2, pipe = 0x3e2d6c8, running = 0
 1487162397.-722522167 usbd_dump_queue#17@0: called!
 1487162397.-722513147 usbd_dump_queue#17@0: pipe = 0x3e2d6c8
 1487162397.-722490384 usb_insert_transfer#14@0: called!
 1487162397.-722478359 usb_insert_transfer#14@0: xfer = 0x3e08e00 pipe = 0x3e2d6c8 running = 0 timeout = 5000
 1487162397.-722460750 usb_insert_transfer#14@0: <- done xfer 0x3e08e00, err 0
 1487162397.-722446147 roothub_ctrl_start#10@0: called!
 1487162397.-722433692 roothub_ctrl_start#10@0: type=0xa3 request= 0
 1487162397.-722411788 uhci_roothub_ctrl#10@0: called!
 1487162397.-722401480 uhci_roothub_ctrl#10@0: type=0xa3 request=00
 1487162397.-722373563 uhci_roothub_ctrl#10@0: returning 4
 1487162397.-722362396 roothub_ctrl_start#10@0: xfer 0x3e08e00 buflen -1 actlen 4
 1487162397.-722354236 roothub_ctrl_start#10@0: xfer 0x3e08e00 err 0
 1487162397.-722339633 usb_transfer_complete#18@0: called!
 1487162397.-722330614 usb_transfer_complete#18@0: pipe = 0x3e2d6c8 xfer = 0x3e08e00 status = 0 actlen = 4
 1487162397.-722313864 usb_transfer_complete#18@0: xfer 0x3e08e00: repeat 0 new head = 0x0
 1487162397.-722301408 usb_transfer_complete#18@0: xfer 0x3e08e00 doing done 0x2a4dbc
 1487162397.-722287665 usb_transfer_complete#18@0: xfer 0x3e08e00 doing callback 0x0 status 0
 1487162397.-722279075 usb_transfer_complete#18@0: <- done xfer 0x3e08e00, wakeup
 1487162397.-722261036 usbd_start_next#18@0: called!
 1487162397.-722248581 usbd_start_next#18@0: pipe = 0x3e2d6c8, xfer = 0x0
 1487162397.-722230113 usbd_transfer#14@0: <- done transfer 0x3e08e00, err = 0
 1487162397.-722222382 usbd_transfer#14@0: <- done xfer 0x3e08e00, err 0 (complete/error)
 1487162397.-722203914 usbd_free_xfer#14@0: called!
 1487162397.-722192747 usbd_free_xfer#14@0: 0x3e08e00
 1487162397.-722172990 usb_freemem#7@0: called!
 1487162397.-722158388 usb_freemem#7@0: frag=0xd5de00
 1487162397.-528899393 uhci_poll_hub#12@0: called!
 1487162398.544507240 uhci_poll_hub#13@0: called!
 1487162398.1618357537 uhci_poll_hub#14@0: called!
 
 ---
 


Home | Main Index | Thread Index | Old Index