Re: uhci doesn't work on VMware Fusion

From: Stefan Bethke <stb_at_lassitu.de> Date: Sat, 28 Mar 2009 13:21:57 +0100 · This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:45 UTC

Am 28.03.2009 um 12:38 schrieb Hans Petter Selasky:

> On Saturday 28 March 2009, Stefan Bethke wrote:
>> I've run into the same issue a couple of days ago.
>>
>> Loading uhci as a module is sufficient to trigger the messages. No
>> device was attached during the output below; in other tests I noticed
>> that uhci appears to not see any device that VMware has attached.
>>
>> This was working just fine with the old stack.
>
> Maybe it has got something to do with the new power save  
> functionality, which
> maybe VMware does not support.
>
> Try:
>
> usbconfig power_on
>
> Then give a USB device to VM-ware.

First try, no device attached:
kldload uhci
sysctl hw.usb2.uhci.debug=15
sleep 5
kldunload uhci

Second try, no device attached:
kldload uhci
sleep 2
usbconfig power_on
sysctl hw.usb2.uhci.debug=15
sleep 5
usbconfig list
kldunload uhci

Third try, 1 GB USB stick attached:
kldload uhci
sleep 2
usbconfig power_on
sysctl hw.usb2.uhci.debug=15
sleep 5
usbconfig list
kldunload uhci

On the third try, usbconfig did not list the device.

I've attached the log output from the second and third tries.

Stefan

#!/bin/sh

kldload uhci
sleep 2
usbconfig power_on
sysctl hw.usb2.uhci.debug=15
sleep 5
usbconfig list
kldunload uhci                                     

# ./test.sh 
usbconfig: could not set power ON: Invalid argument
hw.usb2.uhci.debug: 0 -> 15
ugen0.1: <UHCI root HUB Intel> at usbus0, cfg=0 md=HOST spd=FULL (12Mbps)
pwr=ON

uhci0: <Intel 82371AB/EB (PIIX4) USB controller> port 0x2080-0x209f irq 18 at device 0.0 on pci2
uhci0: [ITHREAD]
usbus0: <Intel 82371AB/EB (PIIX4) USB controller> on uhci0
usbus0: 12Mbps Full Speed USB v1.0
ugen0.1: <Intel> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
uhub0: 2 ports with 2 removable, self powered
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001ccb9d00) at 0x1ccb9d04 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff001ccb9d00) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aec500 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aec500 from 0xffffff0001aec500
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aec500 from 0xffffff001cc8fc80
usb2_alloc_device:1516: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001cce0500) at 0x1cce0504 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x1fe03260
TD(0xffffff001cce0500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001bf6680 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff001cce0500) at 0x1cce0504 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x1fe03260
TD(0xffffff001cce0500) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001bf6680 from 0xffffff0001bf6680
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff000134f500) at 0x0134f504 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000134f500) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff0001aef380 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff000134f500) at 0x0134f504 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000134f500) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001aef380 from 0xffffff0001aef380
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aef380 from 0xffffff001cc8fc80
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff0001600d00) at 0x01600d04 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff0001600d00) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aeda80 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aeda80 from 0xffffff0001aeda80
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aeda80 from 0xffffff001cc8fc80
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00013dc500) at 0x013dc504 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x1fe03260
TD(0xffffff00013dc500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001cc8e280 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00013dc500) at 0x013dc504 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x1fe03260
TD(0xffffff00013dc500) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001cc8e280 from 0xffffff001cc8e280
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff00014d5900) at 0x014d5904 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff00014d5900) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001cc8e300 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00014d5900) at 0x014d5904 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff00014d5900) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001cc8e300 from 0xffffff001cc8e300
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8e300 from 0xffffff001cc8fc80
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00015a8900) at 0x015a8904 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff00015a8900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001cc8f400 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cc8f400
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cc8fc80
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
ugen0.2: <> at usbus0 (disconnected)
uhub_reattach_port:413: could not allocate new device!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0001 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=1
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_set_hw_power:3336: 
uhci_set_hw_power:3358: Power save on 0.
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0001
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0011 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=17
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0010 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=16
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2424: Activating SOFs!
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0281
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0081
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_pipe_init:3185: pipe=0xfffffffe40c013d0, addr=0, endpt=0, mode=0 (1)
uhci_set_hw_power:3336: 
uhci_set_hw_power:3354: Some USB transfer is active on 0.
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff0001bf2d00) at 0x01bf2d04 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x1fe03260
TD(0xffffff0001bf2d00) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001c7d200 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff0001bf2d00) at 0x01bf2d04 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x1fe03260
TD(0xffffff0001bf2d00) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001c7d200 from 0xffffff0001c7d200
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff0001bf1900) at 0x01bf1904 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001bf1900) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001cc8f400 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff0001bf1900) at 0x01bf1904 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001bf1900) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cc8f400
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cc8fc80
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff0001bf1900) at 0x01bf1904 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff0001bf1900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aec400 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aec400 from 0xffffff0001aec400
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aec400 from 0xffffff001cc8fc80
usb2_alloc_device:1516: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00015a7900) at 0x015a7904 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x1fe03260
TD(0xffffff00015a7900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aed700 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00015a7900) at 0x015a7904 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x1fe03260
TD(0xffffff00015a7900) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001aed700 from 0xffffff0001aed700
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff001ccbb100) at 0x1ccbb104 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff001ccbb100) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001cc8e300 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff001ccbb100) at 0x1ccbb104 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff001ccbb100) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001cc8e300 from 0xffffff001cc8e300
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8e300 from 0xffffff001cc8fc80
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff000174f100) at 0x0174f104 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff000174f100) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aeea80 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aeea80 from 0xffffff0001aeea80
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aeea80 from 0xffffff001cc8fc80
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff000134fd00) at 0x0134fd04 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x1fe03260
TD(0xffffff000134fd00) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001ccef980 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff000134fd00) at 0x0134fd04 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x1fe03260
TD(0xffffff000134fd00) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001ccef980 from 0xffffff001ccef980
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff000174d500) at 0x0174d504 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d500) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001ccee680 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff000174d500) at 0x0174d504 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d500) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001ccee680 from 0xffffff001ccee680
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001ccee680 from 0xffffff001cc8fc80
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001cce0500) at 0x1cce0504 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x1fe03260
TD(0xffffff001cce0500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aec500 to 0xffffff001cc8fc80
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aec500 from 0xffffff0001aec500
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aec500 from 0xffffff001cc8fc80
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
ugen0.2: <> at usbus0 (disconnected)
uhub_reattach_port:413: could not allocate new device!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0001 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=1
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=0
uhci_device_done:1844: xfer=0xffffff001ce05948, pipe=0xfffffffe40bff420, error=5
ugen0.1: <Intel> at usbus0 (disconnected)
uhci_device_done:1844: xfer=0xffffff00016db148, pipe=0xfffffffe40bff3d0, error=5
usbus0: detached
uhci_reset:261: resetting the HC
uhci0: detached

#!/bin/sh

kldload uhci
sleep 2
usbconfig power_on
sysctl hw.usb2.uhci.debug=15
sleep 5
usbconfig list
kldunload uhci

root_at_freebsd-current:~# ./test.sh 
usbconfig: could not set power ON: Invalid argument
hw.usb2.uhci.debug: 0 -> 15
ugen0.1: <UHCI root HUB Intel> at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON

usbus0: <Intel 82371AB/EB (PIIX4) USB controller> on uhci0
usbus0: 12Mbps Full Speed USB v1.0
ugen0.1: <Intel> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
uhub0: 2 ports with 2 removable, self powered
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00013dc100) at 0x013dc104 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff00013dc100) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001afd680 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001afd680 from 0xffffff0001afd680
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001afd680 from 0xffffff001cce9080
usb2_alloc_device:1516: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001ccba100) at 0x1ccba104 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x0b403260
TD(0xffffff001ccba100) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001c7f000 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff001ccba100) at 0x1ccba104 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x0b403260
TD(0xffffff001ccba100) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001c7f000 from 0xffffff0001c7f000
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff000174d100) at 0x0174d104 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d100) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff0001c7f100 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff000174d100) at 0x0174d104 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d100) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001c7f100 from 0xffffff0001c7f100
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001c7f100 from 0xffffff001cce9080
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff0001bf2100) at 0x01bf2104 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff0001bf2100) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001cc8d900 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff001cc8d900 from 0xffffff001cc8d900
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8d900 from 0xffffff001cce9080
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00014d4500) at 0x014d4504 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x0b403260
TD(0xffffff00014d4500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001cc8d900 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00014d4500) at 0x014d4504 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x0b403260
TD(0xffffff00014d4500) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001cc8d900 from 0xffffff001cc8d900
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff00014b1900) at 0x014b1904 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff00014b1900) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff0001aec800 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00014b1900) at 0x014b1904 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff00014b1900) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001aec800 from 0xffffff0001aec800
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aec800 from 0xffffff001cce9080
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001ccbb500) at 0x1ccbb504 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff001ccbb500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aed400 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aed400 from 0xffffff0001aed400
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aed400 from 0xffffff001cce9080
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
ugen0.2: <> at usbus0 (disconnected)
uhub_reattach_port:413: could not allocate new device!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0001 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=1
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_set_hw_power:3336: 
uhci_set_hw_power:3358: Power save on 0.
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0001
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0011 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=17
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0010 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=16
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2424: Activating SOFs!
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0281
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0081
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_pipe_init:3185: pipe=0xfffffffe40c013d0, addr=0, endpt=0, mode=0 (1)
uhci_set_hw_power:3336: 
uhci_set_hw_power:3354: Some USB transfer is active on 0.
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff001ccb9900) at 0x1ccb9904 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x0b403260
TD(0xffffff001ccb9900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001c7f000 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff001ccb9900) at 0x1ccb9904 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x0b403260
TD(0xffffff001ccb9900) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001c7f000 from 0xffffff0001c7f000
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff0001659d00) at 0x01659d04 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001659d00) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff0001afd500 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff0001659d00) at 0x01659d04 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001659d00) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001afd500 from 0xffffff0001afd500
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001afd500 from 0xffffff001cce9080
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff000174d500) at 0x0174d504 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff000174d500) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001c7ee00 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001c7ee00 from 0xffffff0001c7ee00
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001c7ee00 from 0xffffff001cce9080
usb2_alloc_device:1516: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00015a7900) at 0x015a7904 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x0b403260
TD(0xffffff00015a7900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001afd680 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff00015a7900) at 0x015a7904 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x0b403260
TD(0xffffff00015a7900) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff0001afd680 from 0xffffff0001afd680
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff000174d500) at 0x0174d504 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d500) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001ccef980 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff000174d500) at 0x0174d504 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff000174d500) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001ccef980 from 0xffffff001ccef980
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001ccef980 from 0xffffff001cce9080
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff00014b1900) at 0x014b1904 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff00014b1900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff0001aa0700 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff0001aa0700 from 0xffffff0001aa0700
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff0001aa0700 from 0xffffff001cce9080
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x03 wLen=0x0000 wValue=0x0004 wIndex=0x0002
uhci_portreset:2439: uhci port 2 reset, status0 = 0x0285
uhci_portreset:2456: uhci port 2 reset, status1 = 0x0085
uhci_portreset:2469: uhci port 2 iteration 0, status = 0x0085
uhci_portreset:2507: uhci port 2 reset, status2 = 0x0085
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0002
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0014 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=20
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=8 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff0001601900) at 0x01601904 = link=0x00000001 status=0x198003ff token=0x00e0002d buffer=0x0b403260
TD(0xffffff0001601900) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=0,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001ccee380 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff0001601900) at 0x01601904 = link=0x00000001 status=0x19000007 token=0x00e0002d buffer=0x0b403260
TD(0xffffff0001601900) td_next=-T td_status=-IOC, errcnt=3, actlen=8 pid=2d,addr=0,endpt=0,D=0,maxlen=8
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001ccee380 from 0xffffff001ccee380
uhci_setup_standard_chain:1662: addr=0 endpt=0 sumlen=0 speed=2
uhci_setup_standard_chain:1823: nexttog=1; data before transfer:
TD(0xffffff0001bf2100) at 0x01bf2104 = link=0x00000001 status=0x398003ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001bf2100) td_next=-T td_status=-ACTIVE-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
_uhci_append_qh:918: 0xffffff001ccef700 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_non_isoc_done:1185: xfer=0xfffffffe40c03148 pipe=0xfffffffe40c013d0 transfer done
TD(0xffffff0001bf2100) at 0x01bf2104 = link=0x00000001 status=0x390007ff token=0xffe80069 buffer=0x00000000
TD(0xffffff0001bf2100) td_next=-T td_status=-IOC-SPD, errcnt=3, actlen=0 pid=69,addr=0,endpt=0,D=1,maxlen=0
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=0
_uhci_remove_qh:974: 0xffffff001ccef700 from 0xffffff001ccef700
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001ccef700 from 0xffffff001cce9080
uhci_setup_standard_chain:1662: addr=2 endpt=0 sumlen=16 speed=2
uhci_setup_standard_chain:1823: nexttog=0; data before transfer:
TD(0xffffff000174d100) at 0x0174d104 = link=0x00000001 status=0x198003ff token=0x00e0022d buffer=0x0b403260
TD(0xffffff000174d100) td_next=-T td_status=-ACTIVE-IOC, errcnt=3, actlen=0 pid=2d,addr=2,endpt=0,D=0,maxlen=8
_uhci_append_qh:918: 0xffffff001cc8f400 to 0xffffff001cce9080
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_check_transfer_sub:1287: xfer=0xfffffffe40c03148 following alt next
uhci_check_transfer:1386: xfer=0xfffffffe40c03148 is still active
uhci_timeout:1493: xfer=0xfffffffe40c03148
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=20
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cc8f400
uhci_device_done:1844: xfer=0xfffffffe40c03148, pipe=0xfffffffe40c013d0, error=5
_uhci_remove_qh:974: 0xffffff001cc8f400 from 0xffffff001cce9080
usb2_req_re_enumerate:1434: getting device descriptor at addr 2 failed!
ugen0.2: <> at usbus0 (disconnected)
uhub_reattach_port:413: could not allocate new device!
uhci_root_ctrl_start:2524: 
uhci_root_ctrl_done:2569: type=0x23 request=0x01 wLen=0x0000 wValue=0x0001 wIndex=0x0002
uhci_root_ctrl_done:2679: UR_CLEAR_PORT_FEATURE port=2 feature=1
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=0
uhci_device_done:1844: xfer=0xffffff00016af948, pipe=0xfffffffe40bff420, error=5
ugen0.1: <Intel> at usbus0 (disconnected)
uhci_device_done:1844: xfer=0xffffff0001b92148, pipe=0xfffffffe40bff3d0, error=5
usbus0: detached
uhci_reset:261: resetting the HC
uhci0: detached

-- 
Stefan Bethke <stb_at_lassitu.de>   Fon +49 151 14070811