From owner-freebsd-current@freebsd.org Sun Feb 21 13:34:09 2016 Return-Path: Delivered-To: freebsd-current@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 4ABDDAB025C for ; Sun, 21 Feb 2016 13:34:09 +0000 (UTC) (envelope-from dim@FreeBSD.org) Received: from tensor.andric.com (tensor.andric.com [87.251.56.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "tensor.andric.com", Issuer "COMODO RSA Domain Validation Secure Server CA" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 11E71197A for ; Sun, 21 Feb 2016 13:34:08 +0000 (UTC) (envelope-from dim@FreeBSD.org) Received: from [IPv6:2001:7b8:3a7::84a9:2d62:ed8b:3361] (unknown [IPv6:2001:7b8:3a7:0:84a9:2d62:ed8b:3361]) (using TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by tensor.andric.com (Postfix) with ESMTPSA id 595F0205B2; Sun, 21 Feb 2016 14:34:05 +0100 (CET) Subject: Re: new computer, strange usb messages at boot Mime-Version: 1.0 (Mac OS X Mail 9.2 \(3112\)) Content-Type: multipart/signed; boundary="Apple-Mail=_3CEA6D52-F5D9-40A5-8D90-F63D3ECB0CEA"; protocol="application/pgp-signature"; micalg=pgp-sha1 X-Pgp-Agent: GPGMail 2.6b2 (ebbf3ef) From: Dimitry Andric In-Reply-To: <56C8310B.4010908@selasky.org> Date: Sun, 21 Feb 2016 14:33:59 +0100 Cc: freebsd-current@freebsd.org Message-Id: <9F54F75F-9FF4-4587-8FFD-C6BE6DC20E17@FreeBSD.org> References: <20160220051951.GA47875@lrosenman-dell.lerctr.org> <56C8310B.4010908@selasky.org> To: Hans Petter Selasky X-Mailer: Apple Mail (2.3112) X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 21 Feb 2016 13:34:09 -0000 --Apple-Mail=_3CEA6D52-F5D9-40A5-8D90-F63D3ECB0CEA Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=us-ascii On 20 Feb 2016, at 10:25, Hans Petter Selasky wrote: >=20 > On 02/20/16 06:19, Larry Rosenman wrote: >> ugen0.2: at usbus0 >> Root mount waiting for: usbus0 >> usbd_setup_device_desc: getting device descriptor at addr 2 failed, = USB_ERR_IOERROR >> Root mount waiting for: usbus0 >> usbd_setup_device_desc: getting device descriptor at addr 2 failed, = USB_ERR_IOERROR >> Root mount waiting for: usbus0 >> Root mount waiting for: usbus0 >> usbd_setup_device_desc: getting device descriptor at addr 2 failed, = USB_ERR_IOERROR >> Root mount waiting for: usbus0 >> usbd_setup_device_desc: getting device descriptor at addr 2 failed, = USB_ERR_IOERROR >> Root mount waiting for: usbus0 >> Root mount waiting for: usbus0 >> usbd_setup_device_desc: getting device descriptor at addr 2 failed, = USB_ERR_IOERROR >=20 > Hi, >=20 > Looks like there is an error enumerating one of the USB devices. It is = harmless. >=20 > What does "pciconf -lv" say about your USB controllers? It might be harmless, but it is surely annoying. Initializing USB devices takes so long because of these errors, that root mounting takes 30 to 40 seconds, and I had to hack in a 15 second pause in /etc/rc.d/zfs to get all my ZFS filesystems on USB disks to mount correctly. If you ask me, something is just seriously broken in the way the xhci driver works on Haswell or higher Intel CPUs. For example, on an embedded Haswell box with USB3 ports: > FreeBSD 10.3-BETA2 #0 r295552: Fri Feb 12 22:28:27 CET 2016 > root@machine:/usr/obj/usr/src/sys/GENERIC amd64 > FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) = 20140512 > VT(efifb): resolution 1920x1200 > CPU: Intel(R) Core(TM) i5-4300U CPU @ 1.90GHz (2494.28-MHz K8-class = CPU) > Origin=3D"GenuineIntel" Id=3D0x40651 Family=3D0x6 Model=3D0x45 = Stepping=3D1 [... e.g., a Haswell ...] > xhci0: mem = 0xf0720000-0xf072ffff at device 20.0 on pci0 > xhci0: 32 bytes context size, 64-bit DMA > xhci0: Port routing mask set to 0xffffffff > usbus0 on xhci0 [...] > ehci0: mem 0xf073d000-0xf073d3ff = at device 29.0 on pci0 > usbus1: EHCI version 1.0 > usbus1 on ehci0 [...] > usbus0: 5.0Gbps Super Speed USB v3.0 > usbus1: 480Mbps High Speed USB v2.0 > ugen0.1: <0x8086> at usbus0 > uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on = usbus0 > ugen1.1: at usbus1 > uhub1: on = usbus1 [... so far so good, now, the waiting starts ...] > Root mount waiting for: usbus1 usbus0 > uhub0: 13 ports with 13 removable, self powered > Root mount waiting for: usbus1 usbus0 > uhub1: 3 ports with 3 removable, self powered > ugen0.2: at usbus0 > ukbd0: on usbus0 > kbd2 at ukbd0 > ugen1.2: at usbus1 > uhub2: on usbus1 > Root mount waiting for: usbus1 usbus0 > uhub2: 8 ports with 8 removable, self powered > usb_alloc_device: set address 3 failed (USB_ERR_TIMEOUT, ignored) > Root mount waiting for: usbus0 > usbd_setup_device_desc: getting device descriptor at addr 3 failed, = USB_ERR_TIMEOUT > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D3, set address failed! (USB_ERR_TIMEOUT, = ignored) > Root mount waiting for: usbus0 > usbd_setup_device_desc: getting device descriptor at addr 3 failed, = USB_ERR_TIMEOUT > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D3, set address failed! (USB_ERR_TIMEOUT, = ignored) > Root mount waiting for: usbus0 > usbd_setup_device_desc: getting device descriptor at addr 3 failed, = USB_ERR_TIMEOUT > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D3, set address failed! (USB_ERR_TIMEOUT, = ignored) > usbd_setup_device_desc: getting device descriptor at addr 3 failed, = USB_ERR_TIMEOUT > Root mount waiting for: usbus0 > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D3, set address failed! (USB_ERR_TIMEOUT, = ignored) > usbd_setup_device_desc: getting device descriptor at addr 3 failed, = USB_ERR_IOERROR > ugen0.3: at usbus0 (disconnected) > uhub_reattach_port: could not allocate new device > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D3, set address failed! (USB_ERR_IOERROR, = ignored) > ugen0.3: at usbus0 > umass0: on = usbus0 > umass0: SCSI over Bulk-Only; quirks =3D 0xc101 > umass0:1:0:-1: Attached to scbus1 > Root mount waiting for: usbus0 > usbd_req_re_enumerate: addr=3D4, set address failed! (USB_ERR_IOERROR, = ignored) > Root mount waiting for: usbus0 > ugen0.4: at usbus0 > umass1: on = usbus0 > umass1: SCSI over Bulk-Only; quirks =3D 0xc101 > umass1:2:1:-1: Attached to scbus2 > Trying to mount root from zfs:zroot/ROOT/stable10-r295552 []... [... here we are at 30 to 40 seconds into the boot, now the umass = retries start ...] > ugen0.3: at usbus0 (disconnected) > umass0: at uhub0, port 10, addr 3 (disconnected) > (probe0:umass-sim0:0:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe0:umass-sim0:0:0:0): CAM status: CCB request completed with an = error > (probe0:umass-sim0:0:0:0): Retrying command > (probe0:umass-sim0:0:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe0:umass-sim0:0:0:0): CAM status: CCB request completed with an = error > (probe0:umass-sim0:0:0:0): Retrying command > (probe0:umass-sim0:0:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe0:umass-sim0:0:0:0): CAM status: CCB request completed with an = error > (probe0:umass-sim0:0:0:0): Retrying command > (probe0:umass-sim0:0:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe0:umass-sim0:0:0:0): CAM status: CCB request completed with an = error > (probe0:umass-sim0:0:0:0): Retrying command > (probe0:umass-sim0:0:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe0:umass-sim0:0:0:0): CAM status: CCB request completed with an = error > (probe0:umass-sim0:0:0:0): Error 5, Retries exhausted > ugen0.3: at usbus0 > umass0: on = usbus0 > umass0: SCSI over Bulk-Only; quirks =3D 0x0100 > umass0:1:0:-1: Attached to scbus1 > ugen0.4: at usbus0 (disconnected) > umass1: at uhub0, port 11, addr 4 (disconnected) > (probe1:umass-sim1:1:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe1:umass-sim1:1:0:0): CAM status: CCB request completed with an = error > (probe1:umass-sim1:1:0:0): Retrying command > (probe1:umass-sim1:1:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe1:umass-sim1:1:0:0): CAM status: CCB request completed with an = error > (probe1:umass-sim1:1:0:0): Retrying command > (probe1:umass-sim1:1:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe1:umass-sim1:1:0:0): CAM status: CCB request completed with an = error > (probe1:umass-sim1:1:0:0): Retrying command > (probe1:umass-sim1:1:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe1:umass-sim1:1:0:0): CAM status: CCB request completed with an = error > (probe1:umass-sim1:1:0:0): Retrying command > (probe1:umass-sim1:1:0:0): INQUIRY. CDB: 12 00 00 00 24 00 > (probe1:umass-sim1:1:0:0): CAM status: CCB request completed with an = error > (probe1:umass-sim1:1:0:0): Error 5, Retries exhausted > da0 at umass-sim0 bus 0 scbus1 target 0 lun 0 > da0: Fixed Direct Access SPC-4 SCSI device > da0: Serial Number NA4BTF51 > da0: 400.000MB/s transfers > da0: 1907729MB (3907029167 512 byte sectors) > da0: quirks=3D0x2 > ugen0.4: at usbus0 > umass1: on = usbus0 > umass1: SCSI over Bulk-Only; quirks =3D 0x0100 > umass1:2:1:-1: Attached to scbus2 > da1 at umass-sim1 bus 1 scbus2 target 0 lun 0 > da1: Fixed Direct Access SPC-4 SCSI device > da1: Serial Number NA4BTF6H > da1: 400.000MB/s transfers > da1: 1907729MB (3907029167 512 byte sectors) > da1: quirks=3D0x2 [...] > ums0: on usbus0 > ums0: 5 buttons and [XYZT] coordinates ID=3D3 Of course initially I also tried some tests with Linux and even Windows on this very same box, and both could enumerate all the USB devices without any errors... -Dimitry --Apple-Mail=_3CEA6D52-F5D9-40A5-8D90-F63D3ECB0CEA Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename=signature.asc Content-Type: application/pgp-signature; name=signature.asc Content-Description: Message signed with OpenPGP using GPGMail -----BEGIN PGP SIGNATURE----- Version: GnuPG/MacGPG2 v2.0.29 iEYEARECAAYFAlbJvM0ACgkQsF6jCi4glqNXcwCcCYO5VaasqgIA9hBH1Ume+zpW lrUAoPqDpYOZzGbz1toS7FGa3P1AsD2h =00E0 -----END PGP SIGNATURE----- --Apple-Mail=_3CEA6D52-F5D9-40A5-8D90-F63D3ECB0CEA--