From owner-freebsd-usb@FreeBSD.ORG Thu Nov 17 19:24:26 2011 Return-Path: Delivered-To: freebsd-usb@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 50DAC106566C for ; Thu, 17 Nov 2011 19:24:26 +0000 (UTC) (envelope-from me@janh.de) Received: from mxchg03.rrz.uni-hamburg.de (mxchg03.rrz.uni-hamburg.de [134.100.38.113]) by mx1.freebsd.org (Postfix) with ESMTP id E8DD28FC17 for ; Thu, 17 Nov 2011 19:24:25 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by mxchg03.rrz.uni-hamburg.de (Postfix) with ESMTP id 012961EE26E; Thu, 17 Nov 2011 20:24:25 +0100 (CET) X-Virus-Scanned: by University of Hamburg ( RRZ / mgw02.rrz.uni-hamburg.de ) Received: from mxchg03.rrz.uni-hamburg.de ([127.0.0.1]) by localhost (mxchg03.rrz.uni-hamburg.de [127.0.0.1]) (amavisd-new, port 10324) with ESMTP id l2o1w7pyXOOi; Thu, 17 Nov 2011 20:24:24 +0100 (CET) Received: from mailhost.uni-hamburg.de (mailhost.uni-hamburg.de [134.100.38.99]) by mxchg03.rrz.uni-hamburg.de (Postfix) with ESMTPS; Thu, 17 Nov 2011 20:24:24 +0100 (CET) Received: from localhost (localhost [127.0.0.1]) by mailhost.uni-hamburg.de (Postfix) with ESMTP id E01369002C; Thu, 17 Nov 2011 20:24:24 +0100 (CET) X-Virus-Scanned: by University of Hamburg (RRZ/mailhost) Received: from mailhost.uni-hamburg.de ([127.0.0.1]) by localhost (mailhost.uni-hamburg.de [127.0.0.1]) (amavisd-new, port 10024) with LMTP id rsv+P9l5jieL; Thu, 17 Nov 2011 20:24:24 +0100 (CET) Received: from pc911.math.uni-hamburg.de (pc911.math.uni-hamburg.de [134.100.220.198]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client did not present a certificate) (Authenticated sender: fmjv004) by mailhost.uni-hamburg.de (Postfix) with ESMTPSA id 838699002B; Thu, 17 Nov 2011 20:24:24 +0100 (CET) Message-ID: <4EC55F6B.5030708@janh.de> Date: Thu, 17 Nov 2011 20:24:27 +0100 From: Jan Henrik Sylvester User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:8.0) Gecko/20111108 Thunderbird/8.0 MIME-Version: 1.0 To: Hans Petter Selasky References: <4EB2F85A.3060501@ixsystems.com> <201111171948.33788.hselasky@c2i.net> <4EC55B27.6060102@janh.de> <201111172007.59113.hselasky@c2i.net> In-Reply-To: <201111172007.59113.hselasky@c2i.net> Content-Type: text/plain; charset=ISO-8859-15; format=flowed Content-Transfer-Encoding: 7bit Cc: Josh Paetzel , "xin@ixsystems.com" , d@delphij.net, freebsd-usb@freebsd.org Subject: Re: USB 3 issues X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 17 Nov 2011 19:24:26 -0000 On 11/17/2011 20:07, Hans Petter Selasky wrote: > 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: 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@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: 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: at usbus1 >>>>>> umass0: 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? Yes, on RC2 the umass attaches as long as the xhci is there -- and that is always the case with r227541. >>>> 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. Except for with default kern.hz, they are linked above. At least without hw.usb.xhci.debug=15, r227541 does not change anything for default kern.hz. As I said, I cannot reproduce the umass failing to attach on RC2. I would have to go back to RC1, if you want to understand that. Anyhow, I am not sure which problem you want to investigate now. RC2+r227541 seems to have solved everything for now. Do you want hw.usb.xhci.debug=15 dmesg with the xhci_timing.patch? Cheers, Jan Henrik