From nobody Tue Mar 15 04:57:26 2022 X-Original-To: freebsd-arm@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4850E1A1D4C9 for ; Tue, 15 Mar 2022 04:57:39 +0000 (UTC) (envelope-from archimedes.gaviola@gmail.com) Received: from mail-ej1-x62a.google.com (mail-ej1-x62a.google.com [IPv6:2a00:1450:4864:20::62a]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "smtp.gmail.com", Issuer "GTS CA 1D4" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4KHh3k3rgqz3QtZ for ; Tue, 15 Mar 2022 04:57:38 +0000 (UTC) (envelope-from archimedes.gaviola@gmail.com) Received: by mail-ej1-x62a.google.com with SMTP id hw13so37213143ejc.9 for ; Mon, 14 Mar 2022 21:57:38 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=3/ihnUfY1qxhWGRFL8BMOXBTE9yvfAvVKvK00vriSrQ=; b=XWKnU40rAiZJj2QFBDs+y5bHIW4cOOi0t/W3TJqY0dckPocJGFPknM+NPCY/o1lzAP p/J8qL2JV4fmPI68e0g8tJrQ/NfRXxGx1YJKBwLDf+TRNhHNibTkB1M2RJ4Nz1GtA9pr zpUCGch0h2wloXD1csWWausND7OhTSUvpfW62/N1CfTYv8swRrcSbJmRtd7fgcIeKGCF fp0JfmprOukg7PzgipYmVwV0DCzKEaWrGSpgxzZpZOTX6bJp4QpwCaetDnkzhpJAOO6X K8BVSIhlELWfJw2S6rssfAD9QzljVZM/0R6UCz30ZGIY+esyodILpyf/WfUj9yFPUbjj F2TQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=3/ihnUfY1qxhWGRFL8BMOXBTE9yvfAvVKvK00vriSrQ=; b=AhXCmgFRd+UG6r4qMwDW33kwzNhtkXOgez5chdLhNRJ6iE0IuMaIclqb5FG8lEEpkN rq6p0Gv5u+5B5DUvZ8faOzybfiiQ9QxqdRHfv9T83yUPFcwEiSewrYAdxqhnK6kKOPju ubmPrl4FtyBTIDoSY/53uzyARFGDub3qklOSpFUNg0m1gfQcztwYbIc6jZcuOt+Z0baY BIguJvE3DBZr/1ZmQrAf7VkhlwSNckyvOwVZGBChhAV6+dmqpdbpMhltEUu3zdPeXMoF EhxTCNvbYmXilL/9qL7XGbCPFobf2w8PLa1Atdc9gwyZpVkGfgIBU8gqmae5VBxyVfZP 2ucQ== X-Gm-Message-State: AOAM532d9gqZjcvL2eaNj7oOXuKeEhdL/GdIWRKJAwcyLGf6M++wI9BS drZTo73vcAedwiH9h0lW87D6sVBIuGwRSakRYiUcSVJzxypS3w== X-Google-Smtp-Source: ABdhPJyv6MOq8LT8wtIwflbL/49uC5Be4AJwZ1UskWzV1cb5witJBWiW6vlc2999TioMrdhJWNF4otXVM1VT3Jsrbck= X-Received: by 2002:a17:907:6d9d:b0:6da:7d4c:287f with SMTP id sb29-20020a1709076d9d00b006da7d4c287fmr20895059ejc.741.1647320257478; Mon, 14 Mar 2022 21:57:37 -0700 (PDT) List-Id: Porting FreeBSD to ARM processors List-Archive: https://lists.freebsd.org/archives/freebsd-arm List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-arm@freebsd.org MIME-Version: 1.0 References: <7c67118e-f6ec-c87d-9a81-3ee6a5952f49@selasky.org> <60f98b10-dcdc-cdf4-3d7a-fe9fd4dff223@selasky.org> <8226461b-5740-9c19-0575-2740bd952e16@selasky.org> <7a77e3bd-1186-56a6-e60e-89e51c190a01@selasky.org> In-Reply-To: From: Archimedes Gaviola Date: Tue, 15 Mar 2022 12:57:26 +0800 Message-ID: Subject: Re: Raspberry Pi 3B USB Printing Issue To: Hans Petter Selasky Cc: freebsd-arm@freebsd.org Content-Type: multipart/alternative; boundary="000000000000c7449305da3aa2b0" X-Rspamd-Queue-Id: 4KHh3k3rgqz3QtZ X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20210112 header.b=XWKnU40r; dmarc=pass (policy=none) header.from=gmail.com; spf=pass (mx1.freebsd.org: domain of archimedesgaviola@gmail.com designates 2a00:1450:4864:20::62a as permitted sender) smtp.mailfrom=archimedesgaviola@gmail.com X-Spamd-Result: default: False [-4.00 / 15.00]; TO_DN_SOME(0.00)[]; FREEMAIL_FROM(0.00)[gmail.com]; R_SPF_ALLOW(-0.20)[+ip6:2a00:1450:4000::/36]; MID_RHS_MATCH_FROMTLD(0.00)[]; DKIM_TRACE(0.00)[gmail.com:+]; RCPT_COUNT_TWO(0.00)[2]; DMARC_POLICY_ALLOW(-0.50)[gmail.com,none]; NEURAL_HAM_SHORT(-1.00)[-1.000]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+,1:+,2:~]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:2a00:1450::/32, country:US]; TAGGED_FROM(0.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com:dkim]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20210112]; FROM_HAS_DN(0.00)[]; NEURAL_HAM_LONG(-1.00)[-1.000]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; PREVIOUSLY_DELIVERED(0.00)[freebsd-arm@freebsd.org]; TO_MATCH_ENVRCPT_SOME(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[2a00:1450:4864:20::62a:from]; MLMMJ_DEST(0.00)[freebsd-arm]; RCVD_COUNT_TWO(0.00)[2]; RCVD_TLS_ALL(0.00)[] X-ThisMailContainsUnwantedMimeParts: N --000000000000c7449305da3aa2b0 Content-Type: text/plain; charset="UTF-8" On Mon, Mar 14, 2022 at 6:12 PM Archimedes Gaviola < archimedes.gaviola@gmail.com> wrote: > > > On Mon, Mar 14, 2022 at 5:31 PM Hans Petter Selasky > wrote: > >> On 3/14/22 10:20, Archimedes Gaviola wrote: >> > On Sun, Mar 13, 2022 at 11:25 PM Archimedes Gaviola < >> > archimedes.gaviola@gmail.com> wrote: >> > >> >> >> >> >> >> On Sun, Mar 13, 2022 at 2:27 PM Archimedes Gaviola < >> >> archimedes.gaviola@gmail.com> wrote: >> >> >> >>> >> >>> >> >>> On Sun, Mar 13, 2022 at 12:38 AM Hans Petter Selasky > > >> >>> wrote: >> >>> >> >>>> On 3/12/22 16:31, Archimedes Gaviola wrote: >> >>>>>> >> >>>>>> IOERROR usually means an electrical error. The RPI3B will use a >> >>>>>> transaction translator for the FULL speed traffic, which is driven >> by >> >>>>>> software. >> >>>>> >> >>>> >> >>>> Hi Archimedes, >> >>>> >> >>>>> Hi Hans, >> >>>>> >> >>>>> I'm curious about the transaction translator you've mentioned, any >> >>>> idea why >> >>>>> there's a need for translation and what is being translated? >> >>>> >> >>>> When the High Speed USB HUB was invented, there was a need to support >> >>>> FULL and LOW speed USB transactions. Because FULL and LOW speed >> >>>> transactions are slow and take up much bandwidth, a transactions >> >>>> translator was invented which translates between High Speed USB and >> >>>> FULL/LOW speed USB. That means the RPi 3B consists of a single USB >> HIGH >> >>>> speed port, followed by a USB HUB. These transactions are not >> visible in >> >>>> usbdump . >> >>>> >> >>>> >Does this only >> >>>>> happen when RPi 3B (acting as host controller) is transmitting data >> to >> >>>> the >> >>>>> Epson printer? Are translation events visible in the usbdump? In >> this >> >>>> case >> >>>>> there's a way to possibly track what's going on and how to identify >> any >> >>>>> info that is being translated? >> >>>> >> >>>> By turning on the HC debugging, you can possibly track via debug >> >>>> messages what is going on. Maybe it is a timing issue, that the SW is >> >>>> too slow serving the micro transactions. >> >>>> >> >>>> Any idea also if translation is being >> >>>>> performed in RPi 4B? >> >>>> >> >>>> The later RPi's do the transaction translator bits in HW or via the >> XHCI >> >>>> block. >> >>>> >> >>>> As I have conducted several printing cases with my >> >>>>> Epson printer without any issues with either of the 4 ports. >> >>>>> >> >>>>> Sorry for these questions as I am catching-up to the USB technology >> >>>>> internal workings under the hood. >> >>>> >> >>>> You are welcome! >> >>>> >> >>> >> >>> >> >>> Thank you so much Hans for answering my questions, really appreciate >> it! >> >>> I have a much better understanding now. >> >>> >> >>> I came from testing with 13.0-RELEASE having the same RPi 3B hardware >> and >> >>> setup and it's very stable. I haven't encountered any IOERROR and >> >>> incomplete printed outputs that were encountered with 14.0-CURRENT >> >>> (February 24, 2022). By the way, I found in the repository here >> >>> https://download.freebsd.org/snapshots/arm64/aarch64/ISO-IMAGES/14.0/ >> >>> that there were two latest snapshots released dated March 3 and March >> 10, >> >>> respectively. I need to take printing tests first, especially the >> latest to >> >>> check if it also manifests before I go back to the Feb. 24 snapshot >> and do >> >>> a thorough test with debugging. I'll provide updates for any >> observations. >> >>> >> >>> Thanks, >> >>> Archimedes >> >>> >> >> >> >> >> >> Hi Hans, >> >> >> >> Initial testing conducted with the latest 14.0-CURRENT (March 10, 2022 >> >> snapshot) seems to be stable. Another test will be performed tomorrow. >> >> >> >> Thanks, >> >> Archimedes >> >> >> > >> > Hi Hans, >> > >> > I still encountered the issue this morning with 14.0-CURRENT (March 10, >> > 2022 snapshot). I just noticed when I left my RPi 3B idle for a long >> period >> > of time (2-3 hours and more) and started printing, then the issue >> pops-up. >> > Another concern I encountered was when I started enabling >> > hw.usb.dwc_otg.debug but after 1-2 minutes my USB keyboard and network >> > interface (remotely connected over SSH from my laptop) seemed to freeze >> and >> > I got disconnected. >> > >> > freebsd@generic:~ % uname -a >> > FreeBSD generic 14.0-CURRENT FreeBSD 14.0-CURRENT #0 >> > main-n253697-f1d450ddee6: Thu Mar 10 09:32:38 UTC 2022 >> > root@releng1.nyi.freebsd.org:/usr/obj/usr/src/arm64.aarch64/sys/GENERIC >> > arm64 >> > >> > root@generic:~ # sysctl -w hw.usb.dwc_otg.debug=1 >> > hw.usb.dwc_otg.debug: 0 -> 1 >> > >> > See attached initial debug info (no printing testing yet). >> > > > Hi Hans, > > >> >> Hi, >> >> Nothing obvious there. >> >> Maybe you need to add a conditional to DPRINTF's in the fast path, to >> only print for a certain device, to reduce the debug prints. >> >> How many USB devices are connected? >> > > Only two devices, one is my USB keyboard and the other one is my Epson > printer. > > >> >> One experiment you might try is to comment out: >> >> usbd_transfer_submit(xfer); >> >> in >> >> uhub_intr_callback() >> >> in >> >> /usr/src/sys/dev/usb/usb_hub.c >> >> It will save some USB resources, but also makes USB enumeration a bit >> slower. > > > This is noted, I'll try. > > >> Maybe the chip is out of USB HW endpoints and is only polling >> for RX data ... >> > > This is noted as well, we'll probably see later what's going on. I'll get > back to you once I recompile the kernel and perform the testing. > > Thanks, > Archimedes > Hi Hans, I did comment-out usbd_transfer_submit(xfer) and still the same behavior is experienced when hw.usb.dwc_otg.debug is enabled. The system seems to freeze as my USB keyboard is unresponsive and I cannot connect over the Ethernet NIC with SSH. I can't print and capture. freebsd@generic:/usr/src/sys/dev/usb % diff -Nur usb_hub.c.orig usb_hub.c --- usb_hub.c.orig 2022-03-14 22:37:03.162678000 +0800 +++ usb_hub.c 2022-03-14 22:38:23.832660000 +0800 @@ -202,7 +202,7 @@ case USB_ST_SETUP: usbd_xfer_set_frame_len(xfer, 0, usbd_xfer_max_len(xfer)); - usbd_transfer_submit(xfer); + /* usbd_transfer_submit(xfer); */ break; Let me know our next step. Thanks, Archimedes --000000000000c7449305da3aa2b0 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable


=
On Mon, Mar 14, 2022 at 6:12 PM Archi= medes Gaviola <archimede= s.gaviola@gmail.com> wrote:


On Mon, Mar 14, 20= 22 at 5:31 PM Hans Petter Selasky <hps@selasky.org> wrote:
On 3/14/22 10:20, Archimedes Gaviola wrote= :
> On Sun, Mar 13, 2022 at 11:25 PM Archimedes Gaviola <
> arch= imedes.gaviola@gmail.com> wrote:
>
>>
>>
>> On Sun, Mar 13, 2022 at 2:27 PM Archimedes Gaviola <
>> = archimedes.gaviola@gmail.com> wrote:
>>
>>>
>>>
>>> On Sun, Mar 13, 2022 at 12:38 AM Hans Petter Selasky <hps@selasky.org>
>>> wrote:
>>>
>>>> On 3/12/22 16:31, Archimedes Gaviola wrote:
>>>>>>
>>>>>> IOERROR usually means an electrical error. The RPI= 3B will use a
>>>>>> transaction translator for the FULL speed traffic,= which is driven by
>>>>>> software.
>>>>>
>>>>
>>>> Hi Archimedes,
>>>>
>>>>> Hi Hans,
>>>>>
>>>>> I'm curious about the transaction translator you&#= 39;ve mentioned, any
>>>> idea why
>>>>> there's a need for translation and what is being t= ranslated?
>>>>
>>>> When the High Speed USB HUB was invented, there was a need= to support
>>>> FULL and LOW speed USB transactions. Because FULL and LOW = speed
>>>> transactions are slow and take up much bandwidth, a transa= ctions
>>>> translator was invented which translates between High Spee= d USB and
>>>> FULL/LOW speed USB. That means the RPi 3B consists of a si= ngle USB HIGH
>>>> speed port, followed by a USB HUB. These transactions are = not visible in
>>>> usbdump .
>>>>
>>>>=C2=A0 =C2=A0>Does this only
>>>>> happen when RPi 3B (acting as host controller) is tran= smitting data to
>>>> the
>>>>> Epson printer? Are translation events visible in the u= sbdump? In this
>>>> case
>>>>> there's a way to possibly track what's going o= n and how to identify any
>>>>> info that is being translated?
>>>>
>>>> By turning on the HC debugging, you can possibly track via= debug
>>>> messages what is going on. Maybe it is a timing issue, tha= t the SW is
>>>> too slow serving the micro transactions.
>>>>
>>>> Any idea also if translation is being
>>>>> performed in RPi 4B?
>>>>
>>>> The later RPi's do the transaction translator bits in = HW or via the XHCI
>>>> block.
>>>>
>>>> As I have conducted several printing cases with my
>>>>> Epson printer without any issues with either of the 4 = ports.
>>>>>
>>>>> Sorry for these questions as I am catching-up to the U= SB technology
>>>>> internal workings under the hood.
>>>>
>>>> You are welcome!
>>>>
>>>
>>>
>>> Thank you so much Hans for answering my questions, really appr= eciate it!
>>> I have a much better understanding now.
>>>
>>> I came from testing with 13.0-RELEASE having the same RPi 3B h= ardware and
>>> setup and it's very stable. I haven't encountered any = IOERROR and
>>> incomplete printed outputs that were encountered with 14.0-CUR= RENT
>>> (February 24, 2022). By the way, I found in the repository her= e
>>> https://download.f= reebsd.org/snapshots/arm64/aarch64/ISO-IMAGES/14.0/
>>> that there were two latest snapshots released dated March 3 an= d March 10,
>>> respectively. I need to take printing tests first, especially = the latest to
>>> check if it also manifests before I go back to the Feb. 24 sna= pshot and do
>>> a thorough test with debugging. I'll provide updates for a= ny observations.
>>>
>>> Thanks,
>>> Archimedes
>>>
>>
>>
>> Hi Hans,
>>
>> Initial testing conducted with the latest 14.0-CURRENT (March 10, = 2022
>> snapshot) seems to be stable. Another test will be performed tomor= row.
>>
>> Thanks,
>> Archimedes
>>
>
> Hi Hans,
>
> I still encountered the issue this morning with 14.0-CURRENT (March 10= ,
> 2022 snapshot). I just noticed when I left my RPi 3B idle for a long p= eriod
> of time (2-3 hours and more) and started printing, then the issue pops= -up.
> Another concern I encountered was when I started enabling
> hw.usb.dwc_otg.debug but after 1-2 minutes my USB keyboard and network=
> interface (remotely connected over SSH from my laptop) seemed to freez= e and
> I got disconnected.
>
> freebsd@generic:~ % uname -a
> FreeBSD generic 14.0-CURRENT FreeBSD 14.0-CURRENT #0
> main-n253697-f1d450ddee6: Thu Mar 10 09:32:38 UTC 2022
> root@releng1.nyi.freebsd.org:/usr/obj/usr/src/arm64.aarch64/sys/GENERI= C
> arm64
>
> root@generic:~ # sysctl -w hw.usb.dwc_otg.debug=3D1
> hw.usb.dwc_otg.debug: 0 -> 1
>
> See attached initial debug info (no printing testing yet).


Hi Hans,
=C2=A0
=

Hi,

Nothing obvious there.

Maybe you need to add a conditional to DPRINTF's in the fast path, to <= br> only print for a certain device, to reduce the debug prints.

How many USB devices are connected?

Onl= y two devices, one is my USB keyboard and the other one is my Epson printer= .
=C2=A0

One experiment you might try is to comment out:

usbd_transfer_submit(xfer);

in

uhub_intr_callback()

in

/usr/src/sys/dev/usb/usb_hub.c

It will save some USB resources, but also makes USB enumeration a bit
slower.

This is noted, I'll try.
=C2=A0
= Maybe the chip is out of USB HW endpoints and is only polling
for RX data ...

This is noted as well, = we'll probably see later what's going on. I'll get back to you = once I recompile the kernel and perform the testing.

Thanks,
Archimedes

=

Hi Hans,

I did comment-o= ut=20 usbd_transfer_submit(xfer) and still the same behavior is experienced when = hw.usb.dwc_otg.debug is enabled. The system seems to freeze as my USB keybo= ard is unresponsive and I cannot connect over the Ethernet NIC with SSH. I = can't print and capture.

freebsd@generic:/= usr/src/sys/dev/usb % diff -Nur usb_hub.c.orig usb_hub.c
--- usb_hub.c.o= rig =C2=A0 =C2=A0 =C2=A02022-03-14 22:37:03.162678000 +0800
+++ usb_hub.= c =C2=A0 2022-03-14 22:38:23.832660000 +0800
@@ -202,7 +202,7 @@

= =C2=A0 =C2=A0 =C2=A0 =C2=A0 case USB_ST_SETUP:
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 usbd_xfer_set_frame_len(xfer, 0, usbd_xfer_= max_len(xfer));
- =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 usbd_= transfer_submit(xfer);
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 /* usbd_transfer_submit(xfer); */
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0= =C2=A0 =C2=A0 =C2=A0 break;

Let me know our next = step.

Thanks,
Archimedes
= =C2=A0
--000000000000c7449305da3aa2b0--