Action Item #472

Boot time speedups

Added by Hammel over 3 years ago. Updated about 5 hours ago.

Status:In ProgressStart date:25 Nov 2015
Priority:ImmediateDue date:
Assignee:Hammel% Done:

30%

Category:09 - Testing
Target version:1.1.0 - Upgrades
Severity:03 - Medium

Description

Some things I can review
  1. Switch to LZO for kernel compression
  2. Delay Loop Calibration: ''lpj=''; can save > 100ms on ARMv5 based systems (boot and look for Calilbrating Delay Loop and check what lpj is set to, then use that on command line)
  3. Parameters for boot time analysis: ''initcall_debug'', ''printk_time=1''
  4. Switch rootfs to UBIfs - better for flash devices
  5. Use initramfs (see slides)
  6. Integrate as many init scripts as possible into single program (my own init program), then use init=myprog

I probably won't get to <1s boot time without bootloader access but I can certainly get to <10s, possibly to <5s.


Related issues

Related to PiBox - Action Item #231: kernel config cleanup In Progress 14 Oct 2013

Associated revisions

Revision 40db28b6
Added by Hammel 14 days ago

RM #472: And lpj, calculated by firstboot, to kernel boot args to speed boot process.

Revision a233f3df
Added by Hammel 5 days ago

RM #472: Speed up module identification and loading, shaving about 7 seconds off the boot time. Fix RPi spi module name.

Revision 05db2a55
Added by Hammel about 5 hours ago

RM #472: Switch to just using mdev (and not nldev) because it's working better now to load needed drivers.

Revision 7225de8b
Added by Hammel about 5 hours ago

RM #472: Speed up the method used to load modules from modules.conf, and remove extraneous modules that are already handled (re: loaded) by mdev.

History

#1 Updated by Hammel 26 days ago

  • Priority changed from Normal to Immediate

#2 Updated by Hammel 26 days ago

  • Target version changed from 1.0 - Atreides to 1.1.0 - Upgrades

#3 Updated by Hammel 21 days ago

  • Status changed from New to In Progress
  • % Done changed from 0 to 10

Other options:

  1. Slides with general boot optimizations

This is mostly the same as the link in the issue description. Some of these would be handled with RM #447 by using squashfs and overlays that are managed by an initramfs init script for booting.

#4 Updated by Hammel 20 days ago

From RM#231:

Looking through dmesg to see boot times I found the following things:

A bunch of eth drivers are compiled in. Only smsc95xx needs to be enabled and even that could be a loadable module.
bcm2708_spi takes 3.5 seconds to load
sda1 (ext4) takes 9 seconds to load
wlan0 takes 8 seconds to load
X (and the fbtft) takes 17 seconds to load

#5 Updated by Hammel 14 days ago

  • % Done changed from 10 to 20

Added lpj to kernel boot args via a firstboot test and updates cmdline.txt.
Changes pushed.

#6 Updated by Hammel 6 days ago

Getting from power on to mounting the SD card takes about 6 seconds on a Pi 2.

[    5.844178] EXT4-fs (mmcblk0p2): recovery complete
[    5.853241] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    5.853328] VFS: Mounted root (ext3 filesystem) readonly on device 179:2.
[    5.863535] devtmpfs: mounted
[    5.870637] Freeing unused kernel memory: 1024K
[    5.870975] Run /sbin/init as init process

Nearly all of this is getting USB and SD access setup. Then getting the RNG takes another 5 seconds.

[    6.156952] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    9.468533] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    9.486838] FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    9.737072] EXT4-fs (mmcblk0p3): mounting ext3 file system using the ext4 subsystem
[    9.758496] EXT4-fs (mmcblk0p3): recovery complete
[    9.758531] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null)
[    9.979002] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[   10.917545] random: crng init done

This can be fixed with preseeding. The rest of the time goes to loading modules. By the time the Bluetooth init script is run,
which is the last one that shows up in dmesg, we're at close to 30 seconds.

[   28.846777] Bluetooth: BNEP socket layer initialized

Things I can do

  • Call log() in all my custom scripts so I can tell which ones are taking a long time. Or at least call log() from rcS to say which script is being called. That will get more info into dmesg.
  • Put network startup in the background. Nothing needs it up front to start, I don't think.
  • Add RNG seeding early in the boot sequence.
  • I see this with at least some wifi drivers: unknown parameter '11n_disable' ignored. I should take those out from the drivers I've seen that message from (rt2800usb, carl9170).
  • There is something happening here that's taking 8 seconds - find out what it is:
[   11.725594] usbcore: registered new interface driver rt2800usb
[   19.922011] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.

I think this is module loading from /etc/modules.conf. I might be able to slurp just the module names from the file and feed them as one request to modprobe.

I feel confident I can get this down to 15 seconds, maybe less, to get to the UI. And with the changes to bootsplash it will seem much quicker.

#7 Updated by Hammel 5 days ago

Module loading was a bottleneck. I fixed the init script to scarf all the module names into a single variable and pass them all at once to modprobe. I also switched from depmod to depmod -A which helped a bunch too. This shaves about 7 seconds off the boot time.

The next biggest bottleneck is mdev. It takes 9 seconds for that to complete. One possible solution is to write a C program that handles all the configuration of usbhandler and friends (from nldev). Still, mdev has to spawn that C program for each device it finds so it's hard to say how much time this would save. I can start by writing usbhandler in C and seeing if that helps.

After a little googling I found that mdev has its own init script that I've been overwriting. If I use it, which has the following:

echo /sbin/mdev >/proc/sys/kernel/hotplug
/sbin/mdev -s # coldplug modules
find /sys/ -name modalias -print0 | xargs -0 sort -u | tr '\n' '\0' | xargs -0 modprobe -abq

then it seems to boot about 6 seconds faster overall, but it also loads a lot more modules (due to that last line). In fact, it loaded the module for the Pi Zero W wifi even though I'd commented it out of the modules.conf and the node came up using that wifi instead of the usb dongle I had connected (which came up as wlan1). So it seems I should drop my mdev script, and possibly drop loading my modules as this takes care of it, and much faster.

Network bring up is about 5.5 seconds. I can put that into the background and hang dependent services off it, like smb.

smb startup, on its own, takes almost 9 seconds. Combined with the network that's almost 15 seconds that could be done in the background so the UI can be up faster.

#8 Updated by Hammel 5 days ago

I commented out all the modules in /etc/modules.conf and tried again. I found the following modules were not loaded automatically by the mdev changes:

snd-bcm2835
spi_bcm2835
uvcvideo

However, there are alot of new drivers loaded. One of them is hid_multitouch. I'm not certain yet but I may need to blacklist that in order for tslib to work. That said, I ran the following and it looks okay:

  1. evtest
    No device specified, trying to scan all of /dev/input/event*
    Available devices:
    /dev/input/event0: ILITEK ILITEK-TP Mouse
    /dev/input/event1: HID 6901:2701
    /dev/input/event2: HID 6901:2701 Mouse
    /dev/input/event3: HID 6901:2701 Consumer Control
    /dev/input/event4: HID 6901:2701 System Control
    /dev/input/event5: ILITEK ILITEK-TP

Despite having hid_multitouch loaded, event5 is mapped correctly to the touchscreen and shows up correctly so maybe I don't need to blacklist that driver. More testing is required.

#9 Updated by Hammel about 5 hours ago

  • % Done changed from 20 to 30

Modules loading is cleaned up for both S10mdev (which now handles many of the module loading duties) and S11dev which does manual modules.conf module loading. It's a bit faster now.
Changes tested, committed and pushed.

log() can't be called by rcS directly (by adding it to the script) because we still need to source the functions script, which in turn sources package specific functions like bumpSplash. Getting rid of psplash (see RM #689) will help here.

So now we're down to this:

[   37.781344] Running /etc/init.d/S97stopsplash

That's the last init process running before the UI gets going. I still think there are things I can do to speed this up, especially if I can offload network startup stuff to run in parallel with UI startup.

Also available in: Atom PDF