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

From: bob prohaska <fbsd_at_www.zefox.net>
Date: Wed, 05 Oct 2022 16:07:37 UTC
On Tue, Oct 04, 2022 at 11:27:00PM -0700, Mark Millard wrote:
> On 2022-Oct-4, at 20:46, bob prohaska <fbsd@www.zefox.net> wrote:
> 
> > 
> > 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.
> 

I'll stick to calling the "good" enclosure 0x0583.



> > 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.
> 

Indeed, I missed it.

> 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.
> 

I gather you're suggesting that debugging delays in EDK2
might not have the same effect as debugging delays in u-boot?
Would it still be worth trying if available?

> 
> Note that U-Boot was not involved at any stage this time.

To my understanding u-boot isn't present, unless I made a
mistake. Are you suggesting something else?

> Adjusting U-Boot would be unlikely to prevent this from
> happening. Nor is it likely that adjusting EDK2 could.

Perhaps, but I don't understand the inference... yet.
AIUI, EDK2 discovers the parameters the kernel needs to
communicate with the disk and passes them to the kernel. 
Is this a distiction between reading the disk and writing?

> 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

The "...request completed with an error... line is rather familiar
and in the past has proved innocuous on Pi3 and I think Pi4, though
not seen recently.

> > 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.
> 

Yes, carriage return.

> > 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.
> 
> > . . .
> 
> 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.
> 

I have made similar observations, but very long (years)
ago. Adding a hub and keyboard seemed to interfere with
boot. Can't remember if it was boot from USB or just 
USB-mounted /usr. There are still some anomalies if a
USB disk is plugged in to a running USB-rooted Pi host.
That seems undesirable, but maybe unavoidable. RasPiOS
has the same problem.

For now buildworld is still in the building libraries 
stage. At the moment it's swap-bound and showing ~750 
MB swap in use at 53% idle. No sign of disk problems
yet. Looks like moutroot is more delicate than I/O.

If there are any EDK2 boot options worth exploring
please indicate. I've seen the help menu but nothing
looks familiar.

Thanks for your continued help!

bob prohaska