Re: u-boot debug, was: Re: U-boot on RPI3, sees disk but won't boot it

On 2022-Oct-4, at 20:46, bob prohaska <fbsd@www.zefox.net> wrote:

> On Tue, Oct 04, 2022 at 01:25:17AM -0700, Mark Millard wrote:
>> I found a configuration that gets the RPi3 EDK2 and FreeBSD
>> combination to have the serial console working. You can try
>> booting and operating via the RPi3 EDK2 UEFI materials.
>> 
> 
> EDK2 boots the JMS576 enclosure rather reliably, 13 out
> of 13 tries succeeded, with no failures.

Note: I prefer the 0x152d:0x0583 identification, just because
it is something I can see in the logs. As I remember, no
log ever shows a "576" from having the specific enclosure in
use.

> It has more problems with the JMS577 enclosure, failing
> mountroot, getting to multi-user twice out of six tries.
> Maybe better to say six interventions from the keyboard.

Well, at least having 0x152d:0x0583 work is a useful
improvement.

> But, seemingly no disk detection failures. I didn't see
> anything that I recognized as an error message from EDK2.
> . . .
> ESC (setup), F1 (shell), ENTER (boot)......BdsDxe: No bootable option or device 
> was found.

That looks like a "no [successful] disk detection
failure" notice by EDK2 and is an example of a EDK2
error report, given that you know there should have
been bootable media accessible.

There is such a thing as a pre-built debug EDK2 build,
at least for RPi4 EDK2. If there is for RPi3 EDK2,
then we might be able to get more message text. But
it need not lead to avoiding the problem.

> BdsDxe: Press any key to enter the Boot Manager Menu.
> . . .
> UEFI firmware (version UEFI Firmware v1.37 built at 19:07:59 on Oct 19 2021)
> . . .
> Consoles: EFI console  
>    Reading loader env vars from /efi/freebsd/loader.env
> Setting currdev to disk1p1:
> FreeBSD/arm64 EFI loader, Revision 1.1
> . . .
> ---<<BOOT>>---
> . . .
> Root mount waiting for: usbus1
> ugen1.4: <GenesysLogic USB2.1 Hub> at usbus1
> uhub2 on uhub1
> uhub2: <GenesysLogic USB2.1 Hub, class 9/0, rev 2.10/6.55, addr 4> on usbus1
> uhub2: 4 ports with 4 removable, self powered
> Root mount waiting for: usbus1
> Root mount waiting for: usbus1
> usb_msc_auto_quirk: UQ_MSC_NO_GETMAXLUN set for USB mass storage device JMicron USB Mass Storage (0x152d:0x0577)
> usb_msc_auto_quirk: UQ_MSC_NO_PREVENT_ALLOW set for USB mass storage device JMicron USB Mass Storage (0x152d:0x0577)
> usbd_req_re_enumerate: addr=5, set address failed! (USB_ERR_IOERROR, ignored)

That is the FreeBSD kernel having a problem dealing with the
0x152d:0x0577 . We have seen this in your prior logs as well.

Note that U-Boot was not involved at any stage this time.
Adjusting U-Boot would be unlikely to prevent this from
happening. Nor is it likely that adjusting EDK2 could.
Looks like the FreeBSD kernel would have to manage to deal
with the issue via an error recovery handling. There is
no evidence to suggest being able to avoid the problem
occurring.

> . . .
> usbd_setup_device_desc: getting device descriptor at addr 5 failed, USB_ERR_IOERROR

Looks to be a consequence of the above.

> Root mount waiting for: usbus1
> ugen1.5: <JMicron USB Mass Storage> at usbus1
> umass0 on uhub2
> umass0: <JMicron USB Mass Storage, class 0/0, rev 2.10/2.14, addr 5> on usbus1
> umass0:  SCSI over Bulk-Only; quirks = 0x8100
> umass0:0:0: Attached to scbus0
> da0 at umass-sim0 bus 0 scbus0 target 0 lun 0
> da0: <SABRENT  0214> Fixed Direct Access SPC-4 SCSI device
> da0: Serial Number DD564198838F9
> da0: 40.000MB/s transfers
> da0: 953869MB (1953525168 512 byte sectors)
> da0: quirks=0x2<NO_6_BYTE>
> ugen1.6: <FTDI FT232R USB UART> at usbus1
> ugen1.5: <JMicron USB Mass Storage> at usbus1 (disconnected)

Possibly another consequence? Or a new failure?
("addr 5" is, apparently, successfully referenced
a few lines above. So I'm guessing: new failure.)

> umass0: at uhub2, port 4, addr 5 (disconnected)
> (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 74 70 6d af 00 00 01 00 
> (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error
> (da0:umass-sim0:0:0:0): Retrying command, 3 more tries remain
> da0 at umass-sim0 bus 0 scbus0 target 0 lun 0
> da0: <SABRENT  0214>  s/n DD564198838F9 detached
> g_dev_taste: g_dev_taste(da0) failed to g_attach, error=6

A consequence?

> (da0:umass-sim0:0:0:0): Periph destroyed
> umass0: detached
> mountroot: waiting for device /dev/da0s2a...
> usb_msc_auto_quirk: UQ_MSC_NO_GETMAXLUN set for USB mass storage device JMicron USB Mass Storage (0x152d:0x0577)
> usb_msc_auto_quirk: UQ_MSC_NO_TEST_UNIT_READY set for USB mass storage device JMicron USB Mass Storage (0x152d:0x0577)

Note that UQ_MSC_NO_TEST_UNIT_READY was nor reported
previously. Likely it indicates another failure lead
to the extra message --or a consequence based failure.

> usb_msc_auto_quirk: UQ_MSC_NO_PREVENT_ALLOW set for USB mass storage device JMicron USB Mass Storage (0x152d:0x0577)
> usbd_req_re_enumerate: addr=5, set address failed! (USB_ERR_IOERROR, ignored)

Like the earlier usbd_req_re_enumerate message.

Looks like the below has some of the same points
as the above sequence. I'll not comment.

> Mounting from ufs:/dev/da0s2a failed with error 19.
> 
> Loader variables:
>  vfs.root.mountfrom=ufs:/dev/da0s2a
>  vfs.root.mountfrom.options=rw
> 
> Manual root filesystem specification:
>  <fstype>:<device> [options]
>      Mount <device> using filesystem <fstype>
>      and with the specified (optional) option list.
> 
>    eg. ufs:/dev/da0s1a
>        zfs:zroot/ROOT/default
>        cd9660:/dev/cd0 ro
>          (which is equivalent to: mount -t cd9660 -o ro /dev/cd0 /)
> 
>  ?               List valid disk boot devices
>  .               Yield 1 second (for background tasks)
>  <empty line>    Abort manual input
> 
> mountroot> usbd_setup_device_desc: getting device descriptor at addr 5 failed, USB_ERR_IOERROR
> ugen1.5: <JMicron USB Mass Storage> at usbus1
> umass0 on uhub2
> umass0: <JMicron USB Mass Storage, class 0/0, rev 2.10/2.14, addr 5> on usbus1
> umass0:  SCSI over Bulk-Only; quirks = 0x8101
> umass0:0:0: Attached to scbus0
> ugen1.5: <JMicron USB Mass Storage> at usbus1 (disconnected)
> umass0: at uhub2, port 4, addr 5 (disconnected)
> (da0:umass-sim0:0:0:0): got CAM status 0xa
> (da0:umass-sim0:0:0:0): fatal error, failed to attach to device
> umass0: detached
> usb_alloc_device: set address 5 failed (USB_ERR_TIMEOUT, ignored)
> ugen1.5: <vendor 0x152d product 0x0577> at usbus1
> umass0 on uhub2
> umass0: <vendor 0x152d product 0x0577, class 0/0, rev 2.10/2.14, addr 5> on usbus1
> umass0:  SCSI over Bulk-Only; quirks = 0x0000
> umass0:0:0: Attached to scbus0
> (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, 3 more tries remain
> da0 at umass-sim0 bus 0 scbus0 target 0 lun 0
> da0: <SABRENT  0214> Fixed Direct Access SPC-4 SCSI device
> da0: Serial Number DD564198838F9
> da0: 40.000MB/s transfers
> da0: 953869MB (1953525168 512 byte sectors)
> da0: quirks=0x2<NO_6_BYTE>

I'm not sure if you did a:

<empty line>    Abort manual input

here or not. If you did, the below is likely
not surprising.

> panic: mountroot: unable to (re-)mount root.
> cpuid = 1
> time = 34
> KDB: stack backtrace:
> #0 0xffff0000004fb6d4 at kdb_backtrace+0x60
> #1 0xffff0000004a6da0 at vpanic+0x13c
> #2 0xffff0000004a6c60 at panic+0x44
> #3 0xffff000000595ac4 at vfs_mountroot+0x1e18
> #4 0xffff00000041ebc4 at start_init+0x28
> #5 0xffff000000455dcc at fork_exit+0x88
> #6 0xffff0000007e56f4 at fork_trampoline+0x14
> Uptime: 34s
> Resetting system ... 
> 
> 
> 
> Raspberry Pi Bootcode
> . . .
> UEFI firmware (version UEFI Firmware v1.37 built at 19:07:59 on Oct 19 2021)
> . . .
> ESC (setup), F1 (shell), ENTER (boot)......
> . . .
> Consoles: EFI console  
>    Reading loader env vars from /efi/freebsd/loader.env
> Setting currdev to disk1p1:
> FreeBSD/arm64 EFI loader, Revision 1.1
> . . .
> ---<<BOOT>>---
> . . .
> Starting background file system checks in 60 seconds.
> 
> Tue Oct  4 20:15:42 PDT 
> FreeBSD/arm64 (pelorus.zefox.org) (ttyu0)
> 
> login: root

No problem observed this time.

> . . .
> 
> At this point I decided to run an overnight buildworld/kernel
> to see how the disk behaves under load.
> 
> 
>> The above actually boots via a default setting that likely
>> should be replaced. The related menu/field nesting is:
>> 
>> Device Manager
>>    Raspberry Pi Configuration
>>        Advanced Configuration
>>            System Table Selection <ACPI + Devicetree>
>> 
>> Picking just Devicetree instead, then saving, and then
>> exiting the nested menus via a sequence of Escape key
>> presses, until back to the initial display, one can
>> then select Reset and it will start over based on the
>> new setting. The save actually updates an area in the
>> RPI_EFI.fd file.
>> 
> 
> I'll try that after the new kernel/userland is installed.
> Is it likely to affect the mountroot issue?

No. So far it seems that FreeBSD is managing to ignore
the ACPI and just use Devicetree. So it is more of a
"lets just be sure to avoid the potential problem"
issue.


On a possible issue: You have

ugen1.6: <FTDI FT232R USB UART> at usbus1

plugged in.

My normal context has just the 1 USB3 NVMe
media, the Ethernet cable, serial console
connection, fan, and power plugged in. (I
ignore the microsd card slot here.) This
works fine. (I do not have a powered hub
involved.)

In in experiments I discovered that if I
plug in an example keyboard (that also
has a mouse plugged into it), it messes
up my ability to boot the RPi3 via, for
example, U-Boot.

It might be worth experimenting with
avoiding having more plugged in than:

Boot USB drive (I count your powered hub as part of this)
Ethernet cable
serial console connection
fan
power

and seeing if boots more often than your
normal configuration vs. not doing so.


===
Mark Millard
marklmi at yahoo.com