RPi4 icon indicating copy to clipboard operation
RPi4 copied to clipboard

Boot takes very long.

Open sharpenedblade opened this issue 3 years ago • 7 comments

A boot using uboot takes around 10 seconds for the kernel to be started, even when chain loading systemd-boot. If the same system uses this UEFI, systemd-boot takes exactly 52 seconds, every time. I recorded this using systemd-analyze, here is the output Startup finished in 10.898s (firmware) + 52.995s (loader) + 2.905s (kernel) + 2.193s (initrd) + 6.604s (userspace) = 1min 15.596s.

I dont think it is entirely the boot loader, becuase, uboot also is an UEFI environment, and this also happens with GRUB. When I look at boot output, the bootloader starts, looks like it loads the kernel, than after around 50 seconds, it has output from the efi stub, and then kernel boot text outputs

sharpenedblade avatar Jul 20 '22 03:07 sharpenedblade

What storage medium is this? SD cards may take very long, USB is prone to overheating and slow SPI Flash takes even longer. External SSD's will likely bring it down to about 30 seconds but with a distinct lack of SSPI, it seems that ship has been sunk... ...and people are expecting several gigabytes of decompression to happen quickly at 25MHz.

TheMindVirus avatar Jul 20 '22 03:07 TheMindVirus

It is on both an sd card, and external (max speed) usb 3.0 drive. It takes the same time on both, so I dont think thats it. It also is after the firmware loads the bootloader, so I think its a bug, usually it takes only a few seconds, on the same hardware and distro.

sharpenedblade avatar Jul 20 '22 06:07 sharpenedblade

I also consider this as a bug. In my case it take to load vmlinux and initrd.img for about 1 minute and 40 seconds with grub. I also setup EFI bootvar for directly loading kernel and initird.img by Linux EFI stub, but it took similar time to boot.

misaz avatar Jul 26 '22 07:07 misaz

A few things to watch out for:

  • If booting after a long time there will be many more memory errors for the storage medium to disk check for
  • Incorrect boot order can delay the process up to 15 seconds but Raspberry Pi boot has been fairly consistent
  • Safe Shutdown with No Internet Connection and USB limited to only Mouse and Keyboard aids consistency
  • Cache Misses occur randomly/sporadically and has the system waiting up to 2 minutes for that to be resolved
  • The Temperature of the storage seems to matter heavily - low temperatures result in reductions of 2 minutes Windows boot time: [2:25:77] - it has been faster before, this was the peak during 7 runs at launch of 500MHz

TheMindVirus avatar Jul 26 '22 11:07 TheMindVirus

If booting after a long time there will be many more memory errors for the storage medium to disk check for

It happens on consecutive boots.

Incorrect boot order can delay the process up to 15 seconds but Raspberry Pi boot has been fairly consistent It happens after the boot loader (systemd-boot) is started

Safe Shutdown with No Internet Connection and USB limited to only Mouse and Keyboard aids consistency

It happens with no USB devices, and with no internet

Cache Misses occur randomly/sporadically and has the system waiting up to 2 minutes for that to be resolved

It happens on every boot, it is not random.

The Temperature of the storage seems to matter heavily - low temperatures result in reductions of 2 minutes Windows boot time: [2:25:77] - it has been faster before, this was the peak during 7 runs at launch of 500MHz

The temperature is cold enough.

I know it is not the OS, because the time is before the initrd is even loaded, and it is much faster, only few seconds with uboot EFI emulation. It is also always consistently 51 or 52 seconds in loader, which means in the efi stub or right before the bootloader loads the efi stub. But it is not the bootloader, because it is with grub and systemd-boot.

sharpenedblade avatar Jul 26 '22 18:07 sharpenedblade

On further inspection this might be down to (as everything has been so far) a mailbox call that returned unexpected results. If this happens then whenever UEFI needs to set the clock rate it will set it to anywhere between 0.6GHz and 1GHz, or a default set from Pcd or config.txt which is a multiple of 1MHz. Either that or this might not be being called at all. Both this and if it doesn't spread the decompression task to all cores evenly, it will result in slow kernel loading time.

>>> Traceback most recent call last: https://github.com/tianocore/edk2-platforms/blob/958fc02b1593cbabb39f4bd317f304f3ab6337de/Platform/RaspberryPi/Drivers/RpiFirmwareDxe/RpiFirmwareDxe.c#L1061 https://github.com/tianocore/edk2-platforms/search?q=RpiFirmwareSetClockRate https://github.com/TheMindVirus/pftf-rpi4/blob/6070b65a02e5ab3ad774d52620c1d136f17c5df3/edk2-platforms/Platform/RaspberryPi/Drivers/ConfigDxe/ConfigDxe.c#L425 https://github.com/TheMindVirus/pftf-rpi4/blob/6070b65a02e5ab3ad774d52620c1d136f17c5df3/edk2-platforms/Platform/RaspberryPi/RaspberryPi.dec#L45

I had set mine to 500MHz for UART stability and it tries by default to use all 4 cores to do the same task (or sometimes just 1). If you have any debug logs, look for "Setting CPU speed to %u MHz\n" or "Setting CPU speed to" in the output. This value at this stage of boot will likely have an impact on everything that comes after it.

TheMindVirus avatar Jul 26 '22 19:07 TheMindVirus

How do I get debug logs, and also if I set the core to max overclock for 60 seconds after boot, will that help.

sharpenedblade avatar Jul 27 '22 19:07 sharpenedblade

Hi all, Currently, I'm able to build and enter the boot menu. My next step is to boot any OS automatically, such as Raspberry Pi OS. Could you please help me how to do that? Thanks!

nguyenanhgiau avatar Apr 14 '23 13:04 nguyenanhgiau

Hi all, Currently, I'm able to build and enter the boot menu. My next step is to boot any OS automatically, such as Raspberry Pi OS. Could you please help me how to do that? Thanks!

You can open a new issue

sharpenedblade avatar Apr 14 '23 23:04 sharpenedblade

usocoreworker.exe and other service workers for windows update on live production windows 10 caused infinite updates. Renaming the file to usocoreworker.exe.old and others has been a temporary solution and with it removed the update GUI times out with a watchdog timer if it can't find USO (Update Orchestrator Service) which was never previously required. It might also be missing on the Pi. Only a select few machines were affected.

TheMindVirus avatar Apr 15 '23 22:04 TheMindVirus

usocoreworker.exe and other service workers for windows update on live production windows 10 caused infinite updates. Renaming the file to usocoreworker.exe.old and others has been a temporary solution and with it removed the update GUI times out with a watchdog timer if it can't find USO (Update Orchestrator Service) which was never previously required. It might also be missing on the Pi. Only a select few machines were affected.

Firmware does not load or use .exe files. That is a windows issue.

sharpenedblade avatar Apr 16 '23 06:04 sharpenedblade

I wonder if my experience falls under the same issue... Boot on a CM4 takes about 30 seconds to load GRUB, then at least 20 minutes from selecting boot option in GRUB to finish. There's no sign of life for around 15 minutes before these messages appear:

EFI stub: Booting Linux Kernel...
EFI stub: Loaded initrd from LINUX_EFI_INITRD_MEDIA_GUID device path
EFI stub: Generating empty DTB
EFI stub: Exiting boot services...

n-hass avatar Dec 11 '23 07:12 n-hass