Reducing boot time on NSA325
May 28, 2020 06:59PM
Hello,

I'm overall satisfied with the performance of my NSA325 + latest u-Boot + Debian on USB flash drive, but one thing that I would like to improve is its boot time. I don't always keep it powered on and it takes more time to boot it than I need to make a cup of tea and get prepared to watch a movie (over SMBfs/minidlna) :-)

Currently it takes about 1 minute from pressing the power button to the moment where I can ping it successfully from another computer.
According to the output of "dmesg" command it takes about 30 seconds to boot Linux system - so I assume another 30 seconds is the system / u-Boot initialisation.
It was 77 seconds before, but I have replaced my flash drive with a faster one, upgraded the kernel and reduced "bootdelay" u-Boot parameter from 3 to 1 - and managed to cut about 17 seconds that way.

Are there any hints / ideas regarding what else can be done to reduce boot time?

(I know that a better idea would probably be buying a more powerful NAS or making my own one - but I'm wondering if there are easy fixes - or not so easy - fixes that can be applied to the current setup - consider it a research project of sort).
Re: Reducing boot time on NSA325
May 28, 2020 08:26PM
Oddly enough we were just talking about this on another thread. A sizeable amount of the time uboot spends initializing is from loading the kernel+initrd into memory before booting them. You can reduce the size of the initrd significantly by limiting the included modules and switching to a more aggressive compression algorthm.
Re: Reducing boot time on NSA325
May 28, 2020 09:09PM
If you are running kernel 5.2.9 and has not upgraded to 5.6.x, then yes that might also be a factor (random seed issue)..

I dont think the size of initrd itself is factor. The works that it load modules from this big initrd is. I built it accomodate sounds and wifi so that's quite a large initrd.

60 seconds is not bad.

====
Edited: typos.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)



Edited 1 time(s). Last edit at 05/28/2020 10:57PM by bodhi.
Re: Reducing boot time on NSA325
May 28, 2020 10:04PM
Good point. 60 sec really is pretty good. Reducing the size of the initrd by a few megabytes might get you a couple seconds faster depending on the speed of the device it is being loaded from. Installing haveged will speed up the filling the entropy pool and allow ssh to start a little faster in some cases.

You could build a custom kernel that does not need an initrd at all which would save even more time since you wouldn’t have to load/unpack/execute the initrd at all.

Like bohdi I wouldn’t put in the effort just to shave a few seconds off of boot time but your use case may be different.
Re: Reducing boot time on NSA325
May 29, 2020 07:13PM
Hello,

Thanks for all the hints.
  1. I think I could really opt for compiling a custom kernel and remove some modules. Should I cross-compile? Are there instructions available for that? @bodhi, could you maybe share some scripts you're using for compiling kernels for kirkwood CPUs?
  2. @1000001101000 getting rid of uInitrd sounds interesting - I have noticed that loading of images takes about 2-3 seconds. Is there any information (here on this forum or somewhere else) how to load kernel directly without uInitrd file?
  3. Can I use netconsole to watch u-Boot loading process? I tried setting IP of my computer to "192.168.0.220" and running "nc -l -u -p 6666" on it as it was described somewhere on this forum but this didn't give me anything - I didn't see any boot messages there. Did I miss something?
  4. Is it possible to set up some sort of profiling / diagnostics / logging for u-Boot booting process - so that I could identify and potentially remove slow points in it?
  5. I've attached the output of dmesg -d command - there are some interesting moments in it:

[    2.560046 <    2.236732>] random: fast init done

Looks like a kernel-level random number generator initialisation. Can it be switched off somehow? Are there any drawbacks?

[    4.160372 <    1.600326>] raid6: int32x8  gen()   151 MB/s
[    4.330190 <    0.169818>] raid6: int32x8  xor()    92 MB/s
[    4.500158 <    0.169968>] raid6: int32x4  gen()   147 MB/s
[    4.670172 <    0.170014>] raid6: int32x4  xor()    96 MB/s
[    4.840068 <    0.169896>] raid6: int32x2  gen()   190 MB/s
[    5.010095 <    0.170027>] raid6: int32x2  xor()   113 MB/s
[    5.180143 <    0.170048>] raid6: int32x1  gen()   133 MB/s
[    5.350181 <    0.170038>] raid6: int32x1  xor()    79 MB/s

Is it just a software RAID6 driver, which I don't need and possibly can remove?

[    6.422669 <    1.069587>] *** VALIDATE bpf ***

Not sure if I need BPF - it's a home media server, which works behind a router and is not directly accessible from the Internet.

[    7.496023 <    0.002157>] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[    7.497145 <    0.001122>] printk: console [ttyS0] disabled
[    7.497225 <    0.000080>] f1012000.serial: ttyS0 at MMIO 0xf1012000 (irq = 26, base_baud = 12500000) is a 16550A
[    8.469125 <    0.971900>] printk: console [ttyS0] enabled

This looks somewhat weird. The console is disabled first and then re-enabled - and all of that takes about 1 second. I'm wondering why this is being done and whether this can be disabled completely. Does it have anything in common with "console=ttyS0,115200" kernel parameter? I might want to switch console off entirely in the end if this helps to cut off 1 second of a boot time.

[   11.045165 <    0.015915>] sd 2:0:0:0: [sda] Attached SCSI removable disk
[   20.671624 <    9.626459>] process '/usr/bin/fstype' started with executable stack
[   20.899216 <    0.227592>] EXT4-fs (sda1): mounting ext3 file system using the ext4 subsystem
[   21.125538 <    0.226322>] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)

This is probably the most interesting part - 9 seconds just to mount rootfs. I'm not sure what's happening there - some sort of filesystem check or anything? Any thoughts on how to prevent that or at least understand what happens?

[   24.892107 <    3.766569>] systemd-udevd[421]: Using default interface naming scheme 'v240'.

I'm not sure what systemd is doing here - is there any way to find out?

Thanks in advance for your help, as always!
Attachments:
open | download - dmesg-2020-05-30.log (24.3 KB)
Re: Reducing boot time on NSA325
May 29, 2020 10:04PM
cross compiling is surprisingly easy (I love how much better these tools have gotten since ~2006 when I first tried them). The script I use to build armel kernels for mv78100 device can be found here:
https://github.com/1000001101000/Debian_on_Buffalo/blob/master/Tools/kernel_tools/build_kernel.sh

here are the prereqs for it:
apt-get -y install libc6-armel-cross libc6-dev-armel-cross binutils-arm-linux-gnueabi libncurses5-dev gcc-arm-linux-gnueabihf gcc-arm-linux-gnueabi build-essential git

You should be able to do something similar by adapting the make command.

Booting with out an initrd requires building in all the drivers needed to mount your rootfs into the kernel (since there will be no initrd to load those drivers anymore). You then need to pass the kernel parameter which specifies what the root device should be similar to:
root=/dev/sda2

I believe there are ways to pass uuid or label rather than device name if needed.

the random number generator is needed by ssh-server among other things and isn't really optional. installing haveged may speed up the initialization, though if it's already up by 3 seconds it's probably already as fast as it's going to get.

I've seen removing the raid6 driver to avoid that check suggested elsewhere as a technique to speed up booting. If you aren't using raid 4/5/6 you can definitely remove it.

I believe you're seeing the kernel switch from the console established by uboot to it's own console. I wouldn't think you could disable the console entirely, I've never had a reason to do that (usually I'm trying to enable one). theoretically increasing the speed of the serial connection might allow it to output text faster and speed up, though I don't know if it would be noticeable.

I suspect mounting speed is largely a function of the drive speed. Looking at one of my kirkwood devices I can see it detect the drive and mount two filesystems and enable swap all within a second with a 16gb ssd I use for testing. I don't know exactly what happens during a mount but I expect it does some sort of cheack of the journal as well as sanity check of the inode table etc.

I go to great lengths to avoid messing with uboot, don't make any uboot changes unless you are prepared to backup/restore uboot via serial console (you should test all changes by serial boot before actually making them). you could look at the bootcmd and see if does something like try several boot methods and ensure that your preferred one is first to save a couple seconds. you could probably custom compile uboot and remove features you don't need to make it load a second or two quicker. though I doubt that would be remotely worth the effort
Re: Reducing boot time on NSA325
May 29, 2020 10:27PM
It is quite a list, so I'll answer where 100.. has not, one by one.

initrd

With Debian kernel, the only way that you would be able to avoid using initrd is to reconfigure the kernel config to compile modules into the kernel as builtin modules. Thus you dont need to load initrd.

But without initrd, you can not use the rootfs label. You would have to use your rootfs partition PART_UUID to tell the kernel where the rootfs is. This has its limitation.

Using an explicit device letter such as /dev/sda1 or /dev/sda2 is not very good. You have no flexibilty in repartition your HDD to put the rootfs partition somewhere else. eg. an HDD enclosure. Or even be able to move your rootfs to sda3, sdb4,... whatever that you need to do in the future.

Suppose your HDD rootfs is corrupted and need fixing with fsck. You would be able to: remove the HDD, plug in a USB rootfs and boot it up, and then reattch the HDD, and fix its rootfs. This is quite easy and requires no change whatsoever if you are using rootfs label.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 29, 2020 11:27PM
U-boot logging

Quote

Is it possible to set up some sort of profiling / diagnostics / logging for u-Boot booting process - so that I could identify and potentially remove slow points in it?

You can use serial console or netconsole to see the boot progress. Serial console will give you everything. Netconsole only shows the activity until the kernel start booting.

Rootfs mounting


Quote

[ 11.045165 < 0.015915>] sd 2:0:0:0: [sda] Attached SCSI removable disk
[ 20.671624 < 9.626459>] process '/usr/bin/fstype' started with executable stack
[ 20.899216 < 0.227592>] EXT4-fs (sda1): mounting ext3 file system using the ext4 subsystem
[ 21.125538 < 0.226322>] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)

This is probably the most interesting part - 9 seconds just to mount rootfs. I'm not sure what's happening there - some sort of filesystem check or anything? Any thoughts on how to prevent that or at least understand what happens?

9 seconds is pretty decent for a typical rootfs that have many packages installed. It is quite easy to understand the rootfs mounting process if you have serial console. You will see all activities.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 29, 2020 11:30PM
Kernel random

Quote

[ 2.560046 < 2.236732>] random: fast init done

Looks like a kernel-level random number generator initialisation. Can it be switched off somehow? Are there any drawbacks?

No, you cannot turn it off. Use haveged , as 100.. recommended above to speed up this part.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 30, 2020 01:22AM
Speeding up U-boot

Since you have the latest u-boot uboot.2017.07-tld-1.nsa325.mtd0.kwb installed, you can speed it up a few seconds by removing some scanning logic.

- Remove boocmd_uenv execution if you don't want to use uEnv.txt to change the booting login on the fly.
- Remove the devices on the device list if you want to ignore all other devices except SATA

fw_setenv devices ide

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 30, 2020 01:26AM
udev

Quote

[ 24.892107 < 3.766569>] systemd-udevd[421]: Using default interface naming scheme 'v240'.

This is the normal udev. In this rootfs, udev has nothing to do with systemd other than the name, and the source code where it resides and built by Debian (in systemd source tree).

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 30, 2020 03:01AM
@bodhi, to clarify: I'm currently booting my NAS from USB flash drive, not from HDD, but I got the point, thank you. Some of that has already been done, like exclusion of extra devices from scanning.

I've installed haveged and it didn't remove random number generator initialization - guess because it's a userspace program.

I can attach a serial console, but wanted to find an easy way to go without disassembly of the NAS box and use net console - at least to interact with u-Boot.
Anyway it seems like I'll have to disassembly it (again) to watch the mounting process.

I will keep you posted! :-)
Re: Reducing boot time on NSA325
May 30, 2020 04:51AM
odmink0,

OK, so rootfs is on USB. What type of USB drive are you using?

Use USB 3.0 flash drive will make booting a lot faster (note that this does not apply to all Kirkwood boxes). But this NSA325 box will play well with USB 3.0 rootfs plugging in one of its USB 2.0 port. This hardware change actually will result in substantial improvement in booting time.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
May 30, 2020 07:08PM
Hello,

Quote
bodhi
Use USB 3.0 flash drive will make booting a lot faster

Agreed - I tried that and it saved me some seconds. But I would prefer to leave it as a "last resort" - right now I'm mostly interested in what can be done purely on the software side.

Quote
1000001101000
cross compiling is surprisingly easy

Thanks for the hint! I tried to recompile the kernel using commands you provided, removed some options that I didn't consider very useful - raid6 PQ benchmark, some self-tests, etc (see the attached config) - and suddenly managed to reduce kernel booting time by about 10s (attaching dmesg as well).
Unfortunately only after doing it I have realized that I've forgotten to apply bodhi's patch - will try to fix that during one of the next iterations.

I've also tried to use a faster LZ4 compression algorithm for the kernel instead of LZMA because it takes U-Boot a couple of seconds only to uncompress the kernel - but apparently large kernels can also be a problem for U-Boot (it complained about too big kernel and rebooted) - so I switched back to LZMA.

I'd still like to try and fight that almost 10s delay during root fs mounting: I used "--verbose debug" kernel command-line options (uEnv.txt came extremely useful here) and it looks to me that it is initramfs scripts doing some hard work there (device detection or something). The log can be viewed at " /run/initramfs/initramfs.debug" when "debug" kernel boot option is present, but I haven't yet realized how to get dmesg-like timestamps there to spot (and potentially eliminate) the slow parts there.
I'm not sure if getting rid of initrd / initramfs completely can help with this. On the one hand, I really like the approach where I can specify root device label - and boot from any USB drive which has the right label, on the other, if it makes me wait extra 10s, I could probably go and specify device UUID at uEnv.txt.

What should I change if I want to stop using initrd?

Thanks!



Edited 1 time(s). Last edit at 05/30/2020 07:10PM by odmink0.
Attachments:
open | download - config-5.6.5-kirkwood-ilya-1 (170.7 KB)
open | download - dmesg-2020-05-31-my2.log (23.4 KB)
Re: Reducing boot time on NSA325
May 30, 2020 09:32PM
odmink0,

>. On the one hand, I
> really like the approach where I can specify root
> device label - and boot from any USB drive which
> has the right label, on the other, if it makes me
> wait extra 10s, I could probably go and specify
> device UUID at uEnv.txt.
>
> What should I change if I want to stop using
> initrd?
>

What you wan to do is changing all the config settings that =m in your .config to =y. And also take out what you don't need, such as sounds and Wifi. When you recompile the kernel, you can also specify no Initrd.

And then create a minimal uInitrd to boot with it. That way no modules will be loaded, but you stil have the benefit of using rootfs label.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
June 01, 2020 07:38PM
Ok, finally: ~25 seconds.

It's the time from power button till the first ping - on a bare system, without systemd, OMV and HDDs. IMHO, this sounds much more reasonable than 60s - can't wait to check the boot time on the fully loaded system.

Primary changes:
* Got rid of uInitrd completely (also removed part of bootcmd that tried to load it), compiled-in necessary modules, using PARTUUID parameter to specify boot partition
* Using LZ4 for kernel compression instead of LZMA - this definitely saves a couple of seconds - "Uncompressing Linux" line disappears almost immediately
* Spotted the problem with that ~10s delay after the mounting of root FS - it was "rootdelay=10" boot parameter - replaced with "rootwait"
* Removed some self-tests (see previously attached config).
* Added "earlyprintk" option to kernel parameters - it has removed that reinitialisation of ttyS0 apparently (although I'm not entirely sure that I used it correctly - without an argument)
* Upgraded kernel to 5.7.0
* Using faster USB 3.0 SLC flash drive (this probably saves another couple of seconds)

I'm wondering what else can be done to reduce this time. I have some other ideas, e.g.:
* Maybe skip some U-Boot initialisation, e.g. of the network card (since I don't think that checking and switching to netconsole works on my box anyway)
* Using kernel concatenated with DTB file - the loading of DTB file separately apparently makes U-Boot use more time
* Switching of PHY interface to auto-negotiation mode when network is available (i.e. network cable is plugged in) takes about 3s during kernel boot - I'm wondering if it can be done earlier / asynchronously, etc.

I will attach the current dmesg / kernel config / U-Boot variables later for those who might want to repeat my steps.



Edited 1 time(s). Last edit at 06/01/2020 07:45PM by odmink0.
Re: Reducing boot time on NSA325
June 02, 2020 09:21AM
another thing you can try is removing unneeded drivers from the kernel. It doesn't look like you have much unneeded stuff but removing the PCI driver and skipping PCI initialization/scanning might be worth a few seconds.
Re: Reducing boot time on NSA325
June 02, 2020 03:57PM
Interesting: I have found out that U-Boot script has some duplicate logic, which of course causes small, but unnecessary delays.

Here are what my boot commands approximately look(ed) like:

bootcmd=\
    run bootcmd_uenv;\  # Initializes devices, reads uEnv.txt
    run scan_disk;\     # Initializes devices (again), loads /boot/uImage
    run set_bootargs;\  # Sets kernel boot args from uEnv.txt
    run bootcmd_exec    # Loads /boot/uImage (again) and DTB file, boots the system

Apparently both device initialization and loading of the kernel from USB drive are duplicated.

I have changed the commands to the following:
# Remove "scan_disk", which apparently only duplicated the scan made by uenv_init_devices
fw_setenv bootcmd 'run bootcmd_uenv; run set_bootargs; run bootcmd_exec'

# Load FDT image with DTB file attached
fw_setenv bootcmd_exec 'run load_uimage; bootm $load_uimage_addr'

There can be a better cleanup performed (e.g. scan_disk could be refactored so that it's used both from bootcmd_uenv and bootcmd_exec, and ignores repeated calls) - maybe sometime in the future I will get around to it :-)

Additionally, as it can be seen from the above command, I decided to go with FDT image which has DTB file attached in the end because it seems like it takes U-Boot more time to load several smaller files than a single big file.
I'm pretty sure that that has saved a couple of seconds as well.

Finally, I have switched to my "full" system now - the one which I typically use - and its boot time (from power button to the first ping) is slightly below 30s - which is slightly more than I had on a bare system, but still is much better than what I had initially.
Re: Reducing boot time on NSA325
June 02, 2020 05:40PM
odmink0,

> Interesting: I have found out that U-Boot script
> has some duplicate logic, which of course causes
> small, but unnecessary delays.

bootcmd_uenv and scan_disk has duplicate logic when you use them together. However, it is necessary for each to be independent (working on its own).

Normally you don't need bootcmd_uenv. scan_disk is what make the booting work.

-bodhi
===========================
Forum Wiki
bodhi's corner (buy bodhi a beer)
Re: Reducing boot time on NSA325
June 02, 2020 05:56PM
So, here's what my final configuration looks like:

/boot/uEnv.txt
custom_params="earlyprintk root=PARTUUID=fdc2cedd-b7e3-9c46-b476-dec6ed5e6616 init=/bin/systemd"

(PARTUUID above is PARTUUID of USB flash partition returned by "blkid" command).

/root/build_fdt_image.sh: (running it manually after each kernel upgrade)
#!/bin/sh
set -e
set -x
cd /boot
KERNEL_VERSION=`uname -r`
mv uImage uImage.orig
cp -a vmlinuz-$KERNEL_VERSION zImage.fdt
cat /usr/lib/linux-image-$KERNEL_VERSION/kirkwood-nsa325.dtb >> zImage.fdt
mkimage -A arm -O linux -T kernel -C none -a 0x00008000 -e 0x00008000 -n $KERNEL_VERSION -d zImage.fdt uImage

Attaching the final kernel config and the output of "dmesg -d" command.

Changes to the U-Boot environment variables are reflected in the previous post (I have also removed "root=LABEL=rootfs" from "bootargs" to get it replaced with uEnv-provided root, but that probably shouldn't matter as it will be overridden by the custom parameter from uEnv.txt).

I think I should assemble back my NAS and see if its boot time is good enough now for my needs - because I can't imagine any other quick wins right now. Maybe building even smaller reduced kernel could help - I think I'll try to build as small kernel as possible at some point in the future.
Attachments:
open | download - config-5.7.0-kirkwood-ilya-1-34 (128.8 KB)
open | download - dmesg-d.log (25.8 KB)
Re: Reducing boot time on NSA325
June 03, 2020 12:26PM
bodhi,

> bootcmd_uenv and scan_disk has duplicate logic
> when you use them together.
>
> However, it is
> necessary for each to be independent (working on
> its own).

I agree - they have to be able to work independently. But when they work together, it would be nice if they used the same function (called e.g. "init_devices") to initialize devices, which would also set some environment variable (e.g. "device") when it's called for the first time, and if this variable is already set, it should skip device initialization and just return.

The same applies to "load_uimage" function.

> Normally you don't need bootcmd_uenv. scan_disk is
> what make the booting work.

Depends, I would say. I had installed that uEnv.txt-handling logic even before I implemented the changes describe in this thread - because I wanted to use systemd. And in general it's useful to be able to pass boot parameters to the kernel via a file on the filesystem.
So, although it's not strictly necessary, but it's a nice-to-have thing.

(Side note: I'm wondering if it's possible to combine loading of the kernel and uEnv.txt file into the single "load" / "ext2load" command?)



Edited 1 time(s). Last edit at 06/03/2020 12:29PM by odmink0.
Author:

Your Email:


Subject:


Spam prevention:
Please, enter the code that you see below in the input field. This is for blocking bots that try to post this form automatically. If the code is hard to read, then just try to guess it right. If you enter the wrong code, a new image is created and you get another chance to enter it right.
Message: