From owner-freebsd-usb@freebsd.org Tue Mar 12 21:44:12 2019 Return-Path: Delivered-To: freebsd-usb@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 4B896153F985 for ; Tue, 12 Mar 2019 21:44:12 +0000 (UTC) (envelope-from hps@selasky.org) Received: from mail.turbocat.net (turbocat.net [88.99.82.50]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 2098787968 for ; Tue, 12 Mar 2019 21:44:10 +0000 (UTC) (envelope-from hps@selasky.org) Received: from hps2016.home.selasky.org (unknown [176.74.212.121]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by mail.turbocat.net (Postfix) with ESMTPSA id 2358A260197; Tue, 12 Mar 2019 22:44:03 +0100 (CET) Subject: Re: strange USB timing issue with u3g To: Mike Tancsa , freebsd-usb@FreeBSD.org References: <3377e001-f035-acec-765c-aee7113f20d4@sentex.net> From: Hans Petter Selasky Message-ID: <2476a53c-e223-1c81-165c-73fa884f30da@selasky.org> Date: Tue, 12 Mar 2019 22:43:39 +0100 User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:60.0) Gecko/20100101 Thunderbird/60.4.0 MIME-Version: 1.0 In-Reply-To: <3377e001-f035-acec-765c-aee7113f20d4@sentex.net> Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US Content-Transfer-Encoding: 8bit X-Rspamd-Queue-Id: 2098787968 X-Spamd-Bar: ------ Authentication-Results: mx1.freebsd.org; spf=pass (mx1.freebsd.org: domain of hps@selasky.org designates 88.99.82.50 as permitted sender) smtp.mailfrom=hps@selasky.org X-Spamd-Result: default: False [-6.50 / 15.00]; RCVD_VIA_SMTP_AUTH(0.00)[]; TO_DN_SOME(0.00)[]; R_SPF_ALLOW(-0.20)[+a:mail.turbocat.net]; MX_GOOD(-0.01)[mail.turbocat.net]; RCPT_COUNT_TWO(0.00)[2]; NEURAL_HAM_SHORT(-0.97)[-0.967,0]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:24940, ipnet:88.99.0.0/16, country:DE]; MID_RHS_MATCH_FROM(0.00)[]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000,0]; FROM_HAS_DN(0.00)[]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[selasky.org]; TO_MATCH_ENVRCPT_SOME(0.00)[]; IP_SCORE(-3.22)[ip: (-9.49), ipnet: 88.99.0.0/16(-4.66), asn: 24940(-1.94), country: DE(-0.01)]; RCVD_COUNT_TWO(0.00)[2]; RCVD_TLS_ALL(0.00)[] X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 12 Mar 2019 21:44:12 -0000 On 3/12/19 9:49 PM, Mike Tancsa wrote: > I have a strange issue I started to see on RELENG11 and RELENG12 that I > am not sure when it started or if its always been there.  On an > PCEngines APU3, with an LTE modem that works with the u3g driver, it > will fail to attach if the box does not boot up fast enough. So I am > guessing something gets messed up in initialization and timing ? > > e.g. in loader.conf I have > > autoboot_delay=2 > dcons_load="YES" > amdsbwd_load="YES" > u3g_load="YES" > beastie_disable="YES" > comconsole_speed="115200" > console="comconsole" > #hw.usb.debug=1 > > > If I pause at the boot or make the delay say 10 seconds, the device > often errors out. The device normally looks like this > > ugen2.1: at usbus2, cfg=0 md=HOST spd=HIGH (480Mbps) > pwr=SAVE (0mA) > ugen1.1: at usbus1, cfg=0 md=HOST spd=HIGH (480Mbps) > pwr=SAVE (0mA) > ugen0.1: <0x1022 XHCI root HUB> at usbus0, cfg=0 md=HOST spd=SUPER > (5.0Gbps) pwr=SAVE (0mA) > ugen2.2: at usbus2, cfg=0 md=HOST > spd=HIGH (480Mbps) pwr=SAVE (100mA) > ugen1.2: at usbus1, cfg=0 md=HOST > spd=HIGH (480Mbps) pwr=SAVE (100mA) > ugen2.3: at usbus2, cfg=0 md=HOST > spd=FULL (12Mbps) pwr=ON (500mA) > > ugen2.3: at usbus2, cfg=0 md=HOST > spd=FULL (12Mbps) pwr=ON (500mA) > >   bLength = 0x0012 >   bDescriptorType = 0x0001 >   bcdUSB = 0x0200 >   bDeviceClass = 0x0000  >   bDeviceSubClass = 0x0000 >   bDeviceProtocol = 0x0000 >   bMaxPacketSize0 = 0x0040 >   idVendor = 0x12d1 >   idProduct = 0x1573 >   bcdDevice = 0x0228 >   iManufacturer = 0x0002  >   iProduct = 0x0003  >   iSerialNumber = 0x0004  <0123456712ABCA17> >   bNumConfigurations = 0x0003 > > > But about 50% of the time with a longer delay, at bootup time I get > > uhub4: 4 ports with 4 removable, self powered > usb_alloc_device: set address 3 failed (USB_ERR_STALLED, ignored) > usbd_setup_device_desc: getting device descriptor at addr 3 failed, > USB_ERR_STALLED > usbd_req_re_enumerate: addr=3, set address failed! (USB_ERR_STALLED, > ignored) > usbd_setup_device_desc: getting device descriptor at addr 3 failed, > USB_ERR_STALLED > usbd_req_re_enumerate: addr=3, set address failed! (USB_ERR_STALLED, > ignored) > usbd_setup_device_desc: getting device descriptor at addr 3 failed, > USB_ERR_STALLED > > > vs > > ugen0.1: <0x1022 XHCI root HUB> at usbus0 > ugen1.1: at usbus1 > ugen2.1: at usbus2 > uhub0: <0x1022 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0 > uhub1: on usbus1 > uhub2: on usbus2 > mmcsd0: 4GB at mmc0 > 50.0MHz/4bit/65535-block > Trying to mount root from ufs:/dev/mmcsd0s1a [ro]... > uhub0: 4 ports with 4 removable, self powered > uhub1: 2 ports with 2 removable, self powered > uhub2: 2 ports with 2 removable, self powered > Starting file system checks: > /dev/mmcsd0s1a: FILE SYSTEM CLEAN; SKIPPING CHECKS > /dev/mmcsd0s1a: clean, 386561 free (3113 frags, 47931 blocks, 0.1% > fragmentation) > ugen1.2: at usbus1 > uhub3 on uhub1 > uhub3: > on usbus1 > ugen2.2: at usbus2 > uhub4 on uhub2 > uhub4: > on usbus2 > /dev/mmcsd0s3: FILE SYSTEM CLEAN; SKIPPING CHECKS > /dev/mmcsd0s3: clean, 2829 free (21 frags, 351 blocks, 0.7% fragmentation) > /etc/rc: WARNING: hostid: unable to figure out a UUID from DMI data, > generating a new one > uhub3: 4 ports with 4 removable, self powered > uhub4: 4 ports with 4 removable, self powered > ugen2.3: at usbus2 > u3g0 on uhub4 > u3g0: 3> on usbus2 > u3g0: Found 5 ports. > > > Enabling debug will make it fail.  Any idea what it might be or how I > can tweak it to it more reliably initializes ? I first start to notice > it when I added a few more klds at boot time. This made the boot up > process that much longer that I would run into this issue periodically. > Hi, Maybe the device expects some kind of BIOS to enumerate it quickly and if not, goes into sleep mode. Try setting: hw.usb.ehci.no_hs=1 In /boot/loader.conf . Does this change anything? USB devices are not allowed to return with a STALL-PID on set-address messages, so this is violation of established USB standards. Maybe you need a USB wire-analyzer to nail this issue. There are a bunch of tunables for example: hw.usb.timings Which affect how the USB device is enumerated. Is your device running the latest firmware from HUAWEI? --HPS