USB 3 issues

Thu Nov 17 19:10:45 UTC 2011

On Thursday 17 November 2011 20:06:15 Jan Henrik Sylvester wrote:
> On 11/17/2011 19:48, Hans Petter Selasky wrote:
> > On Thursday 17 November 2011 19:14:35 Jan Henrik Sylvester wrote:
> >> 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-pa
> >> tch ed-dmesg-0
> >> http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-hz100-pa
> >> tc hed-dmesg-1
> >> http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-debug-hz100-pa
> >> tc hed-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
> >> -pa tched-dmesg-0
> >> http://www.math.uni-hamburg.de/home/sylvester/111117-xhci-nodebug-hz250-
> >> dm esg-0
> > 
> > Hi,
> > 
> > Summed up: You got it working when removing some boot/loader.conf
> > options?
> 
> Sorry for too many details. No:
> 
> I got it working on RC2 with the same setup that failed on RC1.
> 
> For kern.hz=100 or kern.hz=250, I need r227541, while default kern.hz
> works on RC2.

And then UMASS attaches?

> 
> >> 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?
> > 
> > Maybe you can set xhci.debug=0 again, and only send dmesg of what happens
> > when you attach at kern.hz=100 and kern.hz=1000.
> > 
> > I want to see the errors. Not sure yet what actually causes this. I
> > assume that this is maybe a software or hardware timing issue.
> 
> I am not sure what you want: RC1 (with the umass error) without
> hw.usb.xhci.debug=15 is already way above -- at least the relevant part.
> For RC2 (without the umass error), the "nodebug" cases linked above are
> already what you ask for (hz100-patched is kern.hz=100 with r227541,
> hz250 is kern.hz=250 without r227541, and the other is default kern.hz
> without r227541).

I want logs from RC2 with the r227541 patch.

--HPS