On 2023-03-02 22:05:43 +0100, Marek Vasut wrote:
> On 3/2/23 19:51, Janne Grunau wrote:
> > On 2023-03-02 18:33:15 +0100, Marek Vasut wrote:
> > > On 3/2/23 10:14, Janne Grunau wrote:
> > > > On 2023-03-01 23:51:14 +0100, Marek Vasut wrote:
> > > > > On 3/1/23 21:34, Simon Glass wrote:
> > > > > > +Marek Vasut +Bin Meng +Mark Kettenis +Tom Rini
> > > > > >
> > > > > > On Wed, 1 Mar 2023 at 08:12, bluetail
> > > > > > <a-development+as...@posteo.de> wrote:
> > > > > > >
> > > > > > > Essentially, I connect a mass-storage device to the USB-C port of
> > > > > > > a Mac
> > > > > > > Mini 2020 (M1), and it leads to the issue in the attachment.
> > > > > > > I was able to reproduce it with Icy Box IB-3810 and ICY BOX
> > > > > > > IB-3805.
> > > > > > > Initially I thought this issue was only for some devices (also
> > > > > > > attached
> > > > > > > here) https://github.com/AsahiLinux/u-boot/issues/4 but it
> > > > > > > appears this
> > > > > > > might be a issue that is with many devices.
> > > > > > >
> > > > > > > If you need any more information, please feel free to ask. I am
> > > > > > > very
> > > > > > > eager to have this issue fixed because it seems to be a very
> > > > > > > broad issue
> > > > > > > with mass media storage in general.
> > > > > > > uname-r returns 6.1.0-asahi-2-2-edge-ARCH
> > > > > Would it be possible to check whether current u-boot/master works any
> > > > > better
> > > >
> > > > Reproduced with b0eda49bc9b0 ("Merge tag 'u-boot-at91-fixes-2023.04-a'
> > > > of https://source.denx.de/u-boot/custodians/u-boot-at91";) and Icy Box
> > > > IB-3804-C31 (same design as IB-3805/IB-3810 but just a single 4 port
> > > > USB3 hub + 4 independent asmedia usb3 to sata converters).
> > > >
> > > > | scanning bus usb@b02280000 for devices... Device NOT ready
> > > > | Request Sense returned 02 3A 00
> > > > | Device NOT ready
> > > > | Request Sense returned 02 3A 00
> > > > | Resetting EP 0...
> > > > | WARN halted endpoint, queueing URB anyway.
> > > > | Unexpected XHCI event TRB, skipping... (c9208350 0000010f 13000000
> > > > 04008401)
> > > > | "Synchronous Abort" handler, esr 0x96000005
> > > > | elr: 000000000003934c lr : 000000000003934c (reloc)
> > > > | elr: 0000010fcd24034c lr : 0000010fcd24034c
> > >
> > > Could you decode the trace and check where exactly this exception
> > > occurred ?
> > >
> > > It should be enough to run "aarch64-...-objdump -lSD u-boot | less" on the
> > > U-Boot which matches the one which generated the trace, and then look up
> > > the
> > > lr/elr address in that trace. That should point you to the exact place in
> > > code where the exception occurred .
> >
> > Slightly different binary due to unrelated chnages:
> >
> > | scanning bus usb@702280000 for devices... 1 USB Device(s) found
> > | scanning bus usb@b02280000 for devices... 1 USB Device(s) found
> > | scanning bus usb@f02280000 for devices... 1 USB Device(s) found
> > | scanning bus usb@1302280000 for devices... 2 USB Device(s) found
> > | scanning bus usb@702280000 for devices... 1 USB Device(s) found
> > | scanning bus usb@b02280000 for devices... Resetting EP 0...
> > | WARN halted endpoint, queueing URB anyway.
> > | Unexpected XHCI event TRB, skipping... (c92247b0 0000010f 13000000
> > 02008400)
> > | "Synchronous Abort" handler, esr 0x96000005
> > | elr: 0000000000039d9c lr : 0000000000039d9c (reloc)
> > | elr: 0000010fcd240d9c lr : 0000010fcd240d9c
> > | x0 : 0000000000000000 x1 : 00000000000003e8
> > | x2 : 0000000000000040 x3 : 000000000000003f
> > | x4 : 0000010fc9223040 x5 : 0000010fc921ef90
> > | x6 : 0000000000001800 x7 : 00000000300c0300
> > | x8 : 0000000000000424 x9 : 0000000000000008
> > | x10: 00000000ffffffe8 x11: 0000000000000010
> > | x12: 0000000000010000 x13: 0000000000000001
> > | x14: 0000010fc91ba320 x15: 0000000000000021
> > | x16: 0000010fcd23addc x17: 0000000000000040
> > | x18: 0000010fc91e7d70 x19: 0000010fc9223040
> > | x20: 0000010fc9234b20 x21: 0000000000000002
> > | x22: 0000010fc9233790 x23: 0000000000000080
> > | x24: 0000000000000000 x25: 0000010fc91b9d00
> > | x26: 0000010fc91b9d00 x27: 0000010fc9233790
> > | x28: 0000000000000000 x29: 0000010fc91b99b0
> > |
> > | Code: 97ffff3c 52800401 aa1303e0 97ffffa2 (b9400c00)
> >
> > objdump -lSD u-boot | grep -C 12 ' 39d9c'
> >
> > | Disassembly of section .text_rest:
> > | ...
> > | 39d84: f9400c36 ldr x22, [x1, #24]
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:544
> > | xhci_queue_command(ctrl, 0, udev->slot_id, ep_index, TRB_STOP_RING);
> > | 39d88: d2800001 mov x1, #0x0
> > // #0
> > | 39d8c: 97ffff3c bl 39a7c <xhci_queue_command>
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:546
> > | event = xhci_wait_for_event(ctrl, TRB_TRANSFER);
> > | 39d90: 52800401 mov w1, #0x20
> > // #32
> > | 39d94: aa1303e0 mov x0, x19
> > | 39d98: 97ffffa2 bl 39c20 <xhci_wait_for_event>
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:547
> > | field = le32_to_cpu(event->trans_event.flags);
> > | 39d9c: b9400c00 ldr w0, [x0, #12]
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:548
> > | BUG_ON(TRB_TO_SLOT_ID(field) != udev->slot_id);
> > | 39da0: b9494681 ldr w1, [x20, #2372]
> > | 39da4: 6b40603f cmp w1, w0, lsr #24
> > | 39da8: 54000180 b.eq 39dd8 <abort_td+0x8c> // b.none
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:548
> > (discriminator 1)
> > | 39dac: 90000143 adrp x3, 61000 <crc16_tab+0x170>
> > | 39db0: 913d0863 add x3, x3, #0xf42
> > | 39db4: 52804482 mov w2, #0x224
> > // #548
> > | /home/janne/src/asahi/u-boot/drivers/usb/host/xhci-ring.c:549
> > (discriminator 1)
> > | BUG_ON(TRB_TO_EP_INDEX(field) != ep_index);
> > | 39db8: b0000181 adrp x1, 6a000 <names.0+0x11cb>
> >
> > not immediately obvious to me what's the problem. x0 looks valid before the
> > ldr.
>
> x0 in the splat is
> | x0 : 0000000000000000 x1 : 00000000000003e8
> so, I think xhci_wait_for_event() returns NULL .
Indeed, I confused myself earlier since I saw abort_td() finish once.
This is clearly buggy code. 'xhci_wait_for_event(ctrl, TRB_TRANSFER);'
returns NULL on timeouts so the event dereferencing after that needs to
be inside an 'if (event) {}'.
This fixes not the problem as we hit now the 'BUG()' at the end of
xhci_wait_for_event() for TRB_COMPLETION:
| scanning bus usb@b02280000 for devices... Resetting EP 0...
| WARN halted endpoint, queueing URB anyway.
| Unexpected XHCI event TRB, skipping... (c92247b0 0000010f 13000000 02008400)
| XHCI timeout on event type 33... cannot recover.
| BUG at drivers/usb/host/xhci-ring.c:496/xhci_wait_for_event()!
| BUG!
| resetting ..
At least an improvement in the error reporting.
> I found this device locally:
> New USB device found, idVendor=174c, idProduct=55aa, bcdDevice= 1.00
> Product: ICY BOX IB-366StU3+B
>
> I will see if I can reproduce the problem on iMX8MP DWC3 too, unless someone
> wants to dig into it first, which might expedite the fix.
That seems to be a different asmedia usb to sata bridge as it is only 5
gbps instead of 10 gbps. Still worth trying.
Janne
