USB 3 issues

Thu Nov 17 18:14:34 UTC 2011

On 11/15/2011 21:40, Hans Petter Selasky wrote:
> On Tuesday 15 November 2011 14:14:20 Jan Henrik Sylvester wrote:
>> On 11/05/2011 13:15, Hans Petter Selasky wrote:
>>> On Friday 04 November 2011 12:33:53 Jan Henrik Sylvester wrote:
>>>> On 11/04/2011 10:18, Hans Petter Selasky wrote:
>>>>> On Thursday 03 November 2011 22:04:44 Xin LI wrote:
>>>>>> Xin LI
>>>>>
>>>>> Please try the following patch:
>>>>>
>>>>> http://svn.freebsd.org/changeset/base/227075
>>>>>
>>>>> Then send me the XHCI attach error.
>>>>>
>>>>> Probably something which we can fix.
>>>>
>>>> Ok, I have found a minute to test 9.0-RC1 + 227075:
>>>>
>>>> xhci0:<XHCI (generic) USB 3.0 controller>   mem 0xf1f00000-0xf1f0ffff irq
>>>> 19 at device 0.0 on pci5
>>>> xhci0: 32 byte context size.
>>>> xhci0: Controller reset timeout.
>>>> xhci0: XHCI halt/start/probe failed err=18
>>>> WARNING: A USB process has been left suspended
>>>> device_attach: xhci0 attach returned 6
>>>>
>>>> BTW: I think it is this device from "pciconf -l":
>>>> xhci0 at pci0:5:0:0:       class=0x0c0330 card=0x10001d5c chip=0x10001b73
>>>> rev=0x01 hdr=0x00
>>>
>>> In sys/dev/usb/controller/xhci.c
>>>
>>> Try to increase the usb_pause_mtx() from hz/1000 to hz/100.
>>>
>>> If that doesn't work try to continue, even if the HC is not clearing the
>>> HCRST bit. Also print "temp" at the end of the loop.
>>>
>>> 	/* Reset controller */
>>> 	XWRITE4(sc, oper, XHCI_USBCMD, XHCI_CMD_HCRST);
>>> 	
>>> 	for (i = 0; i != 100; i++) {
>>> 	
>>> 		usb_pause_mtx(NULL, hz / 1000);
>>> 		temp = XREAD4(sc, oper, XHCI_USBCMD)&
>>> 		(XHCI_CMD_HCRST | XHCI_STS_CNR);
>>> 		if (!temp)
>>> 		
>>> 			break;
>>> 	
>>> 	}
>>> 	
>>> 	if (temp) {
>>> 	
>>> 		device_printf(sc->sc_bus.parent, "Controller "
>>> 		
>>> 		    "reset timeout.\n");
>>> 		
>>> 		return (USB_ERR_IOERROR);
>>> 	
>>> 	}
>>
>> I have put hz/100 in all four places of usb_pause_mtx(), replacing
>> hz/1000 three times and hz/250 once. temp is never != 0 in that loop now
>> and the controller attaches:
>>
>> xhci0:<XHCI (generic) USB 3.0 controller>  mem 0xf1f00000-0xf1f0ffff irq
>> 19 at d
>> evice 0.0 on pci5
>> xhci0: 32 byte context size.
>> usbus1 on xhci0
>>
>> Anyhow, trying to attach an umass device fails:
>>
>> xhci_do_command: Command timeout!
>> xhci_do_command: Command timeout!
>> xhci_do_command: Command timeout!
>> ugen1.2:<FUJITSU>  at usbus1
>> umass0:<FUJITSU MB86C311, class 0/0, rev 3.00/0.01, addr 1>  on usbus1
>> umass0:  SCSI over Bulk-Only; quirks = 0x0000
>> xhci_do_command: Command timeout!
>> xhci_do_command: Command timeout!
>> umass0: Get Max Lun not supported (USB_ERR_TIMEOUT)
>> umass0:5:0:-1: Attached to scbus5
>> xhci_do_command: Command timeout!
>>
>
> Hi,
>
>> And many more "Command timeout!" after that.
>
> Can you compile the kernel with "options USB_DEBUG" in the kernel
> configuration file and set hw.usb.xhci.debug=15 during bootup?
>
> I will get those delay changes into the mainline code.

I have done some more testing, now on 9.0-RC2/amd64. Thus, I did not 
need the usb_request.c changes from r227075 anymore and used GENERIC 
(from freebsd-update) for some tests and GENERIC plus all (three) "hz / 
1000" changed to "hz / 100" in xhci.c as in r227541 for the others.

First, I removed kern.hz=100 (together with hint.p4tcc.0.disabled=1, 
hint.acpi_throuttle.0.disabled=1, hint.apic.0.clock=0, and 
hint.atrtc.0.clock=0) from loader.conf. Later, I put it back in.

9.0-RC2/amd64 GENERIC with standard kern.hz works: I get /dev/da0 from 
the harddisk attached that I can use subsequently.

9.0-RC2/amd64 GENERIC with kern.hz=100 produces the xhci timeout, but 
with the xhci.c patch, it works, too.

9.0-RC2/amd64 GENERIC with kern.hz=250 without the xhci.c patch does not 
work, either.

"umass0: Get Max Lun not supported" and so on never appeared again. 
(Maybe due to some other changes between RC1 and RC2? There was r226803 
for example and probably more to other related files.)

I did some of the testing with hw.usb.xhci.debug=15 in case you still 
want to have a look. Once (with kern.hz=100), the system did not respond 
anymore, after I repeatedly had run dmesg to see if/when /dev/da0 
appears. Anyhow, I was not able to reproduce that and after I rebooted I 
saw the huge debug output on the first console after attaching the harddisk.

Since I not know if the list takes attachments, some dmesg output are 
here for a few days:

http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-dmesg-0
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-dmesg-1
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-dmesg-2
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-hz100-patched-dmesg-0
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-hz100-patched-dmesg-1
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-hz100-patched-dmesg-2
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-nodebug-dmesg-0
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-nodebug-dmesg-1
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-nodebug-hz100-patched-dmesg-0
http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-nodebug-hz250-dmesg-0

Do you want anything else? Do you want me to go back to 9.0-RC1 and try 
to reproduce the error with hw.usb.xhci.debug=15?

Cheers,
Jan Henrik