Why is GRUB 2 booting so slowly?

Question

I have a small custom embedded Linux distribution (created with OpenEmbedded), which boots with GRUB 1.99. The aim is to have it start up fast.

Currently it says:

GRUB loading.

for ~2+ seconds (this is probably unavoidable). Then:

Welcome to GRUB!

under it for a fraction of a second when it has finished loading.

(There is no menu or menu timeout.) It clears the screen, then:

Booting 'Disk'

for ~8 seconds. This delay seems like it should be avoidable. I'd very much like to know how to make it not delay here.

Then it continues on to:

Decompressing Linux... Parsing ELF... done.
Booting the kernel.

And then lots of fast scrolling text as the kernel boots.

The kernel image file is 1.8MB, and the disk image file is 16MB.

The grub.cfg file looks like:

set default="0"
set timeout=0

menuentry "Disk" {
    set root=(hd0,1)
    linux /boot/Disk.kernel parport=0x378,7,3 ramdisk_size=16384 root=/dev/ram rw
    initrd /boot/Disk.ext2
}

In another boot disk I have (on a Compact Flash card), I have exactly the same kernel, and a different disk image file, which 20MB. The config file is also identical, except that ramdisk_size=20480. This one has an extremely long delay of 69 seconds at that same point. Why is it so much longer? Thankfully, I don't need to use that boot disk often. But it would be nice to fix that one too, since presumably the delay is caused by the same thing.

How do I fix this delay? What is it doing? How does one go about debugging a bootloader? Is it worth looking into a lighter weight bootloader like SYSLINUX instead? Will deleting some of the unused GRUB 2 modules improve it? (How does one find which modules are unused?)

Summary

All of the following have the exact same Linux 3.2 kernel:
Flash disk A on computer X: 16MB image, GRUB 1.99, boot delay is ~8s; disk A's read speed is 20MB/s.
Flash disk B on computer X: 20MB image, GRUB 1.99, boot delay is 69s; disk B's read speed is 20MB/s.

Flash disk C on computer Y: 16MB image, GRUB 0.97, boot delay is.. extremely quick; disk C's read speed is 16MB/s.
Note that computer Y is similar to computer X, but a bit slower.
(The monitor is not even fast enough to show any GRUB screens at all. From the point of the BIOS screen disappearing to the Linux kernel loading screen first appearing, it shows 4.76s of blank screen - but the Linux kernel has already been loading for at least 1.5s by that time, so it's more like 3.2s at a maximum for GRUB to do its thing. This includes GRUB itself loading and BIOS deciding which drive to boot from, etc.)
Unfortunately GRUB 0.97 like that instance is not able to be repeatably built like that, so it doesn't seem like a feasible option (although it would be nice).

How do I make GRUB 2 fast??

Solution 1

I didn't find the cause of the slow booting with GRUB 2.

I ended up using EXTLINUX instead, which is compact and fast, and better-suited if you don't need all the fancy GRUB 2 things.

http://www.syslinux.org/wiki/index.php/EXTLINUX

Solution 2

EDIT: It seems that GRUB2 is the problem in this case, after all. I'm keeping my original answer below just for reference and as an explanation for similar problems people may have.

---

The boot delay you are referring to is the time needed for the kernel and initramfs image to be loaded to RAM. The blame is not on bootloader, it is on the size of your kernel/initramfs and storage (CF card) throughput.

You can easily test the speed of your storage using either dd (if you have it installed on your embedded system) or cat. Just substitute /dev/sda1 below with the name of the block device representing the boot partition on that system (you can usually check that using the mount command).

• using dd: dd if=/dev/sda1 of=/dev/null
• using cat + time: time cat /dev/sda1 > /dev/null

(In the second case, you'd need to calculate the rate manually.)

If your root partition is too large to wait for the commands to finish, just press Ctrl+C after some time (but not less than about one minute, to make the test reliable).

Comments

[rozcietrzewiacz]

Try enabling GRUB2 debugging, by adding set pager=1 and set debug=all to your /boot/grub/grub.cfg file, as described here. And paste the grub.cfg file on some pastebin.com or whatever, so we can have a look at it.

[Jetski S-type]

Thanks, I'll try the debug mode. The grub.cfg is posted above in the question.

[Jetski S-type]

Using this same CF card and card reader device that took 69s to boot from, I did a dd of 998.6MB in 49.8s, which means a data rate of 20.0MB/s. So it took less time to read 1GB off the disk than to read the image/kernel for the boot (which requires only 21.8MB). The other flash disk that took 8s to boot had a very similar data rate. So I'm pretty sure that's not the cause of this boot delay.

[rozcietrzewiacz]

Using a separate card reader (if I understood correctly) to do the test misses the whole point. The throughput is not just limited by capabilities of the card itself, but by the hardware chip used in the adapter/motherboard as well. Do the tests on that very system which has booted from the card.

[Jetski S-type]

That's what I said - "the same CF and card reader device that took 69s to boot". I used the USB card reader with CF card to boot, which took 69s; and I did the dd test with the same USB card reader with CF card, which achieved 20.0MB/s. Therefore, it's roughly 65 times slower in copying the necessary kernel/image when booting than when doing the dd test.

[Jetski S-type]

Just to be clear, there are two separate devices that I did boot timing tests with. The other disk that took 8s to copy the kernel/image when booting is a separate flash disk device (non-CF card). I think that's through an IDE interface rather than USB. I still suspect there's some issue/problem somewhere that's causing both of these boot delays (but to different extents, for some reason).

[rozcietrzewiacz]

Hmm, this is strange... And you did this on the same system (the card reader connected to the same USB port)?

[Jetski S-type]

Yes! Same system, same flash disk, same USB card reader on the same USB port, etc. Everything is identical between the boot and the dd test in both cases. Indeed it is strange... that's why I asked the question here!

[Jetski S-type]

I've updated the question with a summary of some boot delay times, including a GRUB 0.97 boot delay time with slightly inferior hardware.

[rozcietrzewiacz]

This is very interesting. (I'm not sure what you mean by not being able to repeatedly use GRUB 0.97, though. I use it all the time!) Another thing that came to my mind, which might be causing the problem (if not GRUB2 after all) - compression: are the images compressed differently? Typically, embedded hardware can handle gzip very fast, but xz or lzma could be a problem. Anyway, the huge difference seems to indicate that GRUB2 is more likely to be the culprit. Definitely, post your /boot/grub/grub.cfg file for inspection.

[Jetski S-type]

I mean that I have a GRUB 0.97 build on one disk, but I must be able to build it from source for it to be usable in the long term. I tried to build it from source (applying three patches), and it would just refuse to recognise the disk to install to in the install process. I tried all manner of things for a day, then gave up. Why would GRUB 0.97 be much faster at decompressing? It's the same kernel/image. I do think the problem is in GRUB 2, and I did post the grub.cfg in the question - just re-read it.