Ubuntu – GRUB doing while it takes 9 minutes to start booting the kernel

bootgrub2

Lately (at least the last 2 time I turned the PC on) I noticed grub takes forever to boot. I timed almost 9 minutes between the bios messages go away and the kernel log appears on screen.

The question is how can I know what grub is doing or waiting? How can I check grub is ok?

A few days ago I removed the splash screen so I see the text log on every boot. Most of the times it is fast and normal. During those 9 minutes the monitor receives signal, but it is just a black screen. NumLock does not respond, the whole thing appears to be frozen, but it is not.

I have have / on a software raid1 since 2009 at least.

The raid is reported healthy. During those minutes there's some minor hard disk activity in the first minute. Hard drive SMART data is healthy. Shutdown the day before was normal.

I have had all Ubuntu versions installed in this computer since 8.04. I have 12.10 installed since October. There's nothing new in this computer, no new hard drives, no changes in the BIOS settings.

There's no grub log AFAIK and the kernel log is not interesting because it says the kernel booted in 28 seconds [PhenomX4 kernel: [ 28.825313] vboxpci: IOMMU not found (not registered)] so the 9 minutes are before the kernel started.

*Update: march 27th *

I found the problem, but I still don't know the cause. The problem was /boot/grub/grub.cfg was 11.6 MB and it had entries like this one repeated many many times with slight variations. Grub was choking on such a big file to create its menu.

menuentry 'Ubuntu 12.10 (12.10) (en /dev/sda1) (en /dev/sda1) (en /dev/sdb1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1) (en /dev/sda1)' --class gnu-linux --class gnu --class os $menuentry_id_option 'osprober-gnulinux-/vmlinuz--73e06880-5f46-4493-aaef-23fa4ad138f6' {
    insmod part_msdos
    insmod ext2
    set root='hd0,msdos1'
    if [ x$feature_platform_search_hint = xy ]; then
      search --no-floppy --fs-uuid --set=root --hint-bios=hd0,msdos1 --hint-efi=hd0,msdos1 --hint-baremetal=ahci0,msdos1 --hint='hd0,msdos1'  73e06880-5f46-4493-aaef-23fa4ad138f6
    else
      search --no-floppy --fs-uuid --set=root 73e06880-5f46-4493-aaef-23fa4ad138f6
    fi
    linux /vmlinuz root=/dev/sda1
    initrd /initrd.img
}

Still don't know why that file grew so much?

Update march 28th

A big chunk of the menu entries is generated by /etc/grub.d/30_os-prober.

Line 223: ### BEGIN /etc/grub.d/30_os-prober ###
...
Line 175174: ### END /etc/grub.d/30_os-prober ###

grub.cfg has 175191 lines, so that script represents 99% of the 11.6 MB in the file.

Best Answer

There's a nice tool called BootChart included in the repositories. It also has a GRUB debug component provided. these will allow you to profile your boot and hopefully find out what's eating the large chunk of time.

enter image description here