building initramfs is slow

building initramfs is slow

[John Reiser]

Building an initramfs is unreasonably slow.  On Fedora 16
dracut-011 takes almost a minute when installing a new kernel:
   real   56s
   user   20s   \__   dracut is CPU bound, not I/O bound.
   sys    31s   /
The final "gzip -9" takes 12 seconds, and the cpio 1 second,
which leaves 43 seconds for the rest of dracut.  That's a
factor of 3 or 4 too long.  The output initramfs is 14.9MB
(41MB unzipped) and contains 1619 files, including 367 .ko
kernel modules.

Running
   strace -o strace.out -f -e trace=execve dracut test.img
and applying some text processing to strace.out shows
  12518 SIGCHLD   (processes terminated)
So dracut fondles each file with an average of (12518 / 1619)
= 7.7 processes.  No wonder building an initramfs is slow!

Again in strace.out:
   8917 execve    (address-space images instantiated)
and taking (#SIGCHLD - #execve) gives:
   3591 fork-and-no-exec  (shell builtins that need a process)
because there is almost no chaining of execve without a fork.

The sorted histogram of execve begins:
   3803 execve("/bin/egrep"
   1343 execve("/bin/cp"
    858 execve("/lib64/ld-linux-x86-64.so.2"
    760 execve("/usr/bin/ldd"
    375 execve("/sbin/modinfo"
    359 execve("/bin/chmod"
    344 execve("/bin/rm"
    341 execve("/sbin/modprobe"
    256 execve("/bin/mkdir"
    222 execve("/bin/readlink"
    100 execve("/bin/cat"

This data, and a glance at the source of dracut, suggests
considering the bash shell regexp operator "[[ string =~ pattern ]]"
and the expansion substitution operator "${parameter/pattern/string}"
to replace most instances of egrep.

The uses of cp, ldd, chmod, and modinfo should be investigated for
the possibility of batching more than one file at a time.  Operating
inside one directory at a time can effectively remove the threat of
exceeding the 32KB limit on the arglist to execve.

Using pipelines (possibly including bash's "while read fname ; do")
to filter streamed lists of filenames can reduce overhead significantly
in contrast to "for fname in ...; do <<execve>>".  A pipeline may also
introduce effective parallelism.

"sort --uniq" handily removes duplicates.

In most cases "cat filename |" should be replaced with ordinary
redirection "< filename", and similarly "$(cat filename)" should
be "$(< filename)".  If SELinux denies access by dracut (etc.)
but allows /bin/cat, then such a comment is REQUIRED.

Yes, I'm going to work on it.

-- 

Re: building initramfs is slow

[John Reiser]

On 08/18/2011 11:25 AM, Harald Hoyer wrote:
> Try dracut version 013. It's already faster.

Yes, there is some improvement, but I still seek a *factor* of 3 to 4
overall before cpio+gzip.  All the slow coding persists.


$ time /abs/path/to/dracut-013/dracut --local --force test2.img
###  [fixed-width font, please]   contrast to dracut-011
   real  59s                           +3s
   user  26s                           +6s
   sys   29s                           -2s

     26.0MB  output image            + 11.1MB
     69.0MB  unzipped                + 28.0MB
   1947      files listed by cpio    +328  files
    483      .ko kernel modules      +116  modules

## Note the results have gotten larger (time, bytes, files, modules).
## The input (and configuration) has evolved, too.


$ strace -o strace.out -f -e trace=execve /abs/path/to/dracut-013/dracut --local --force test2.img
  11349  SIGCHLD                    -1169  processes   !yea!
   7544  execve                     -1373  execve      !yea!
   3805  fork-and-no-exec           + 214  shell builtins that get a process


   2686 execve("/bin/egrep"         -1117  good, but should be at most a few dozen
   1587 execve("/bin/cp"            + 244
    491 execve("/sbin/modinfo"      + 116
    468 execve("/bin/chmod"         + 109
    458 execve("/bin/rm"
    455 execve("/sbin/modprobe"
    320 execve("/bin/readlink"
    318 execve("/bin/mkdir"
    285 execve("/lib64/ld-linux..."  -573  !yea!
    166 execve("/usr/bin/ldd"        -594  !yea!
    119 execve("/bin/cat"
     88 execve("/bin/ln"
     44 execve("/bin/grep"
     17 execve("/bin/find"

-- 

Re: building initramfs is slow

[WANG Cong]

On Thu, 18 Aug 2011 16:09:19 -0700, John Reiser wrote:

> On 08/18/2011 11:25 AM, Harald Hoyer wrote:
>> Try dracut version 013. It's already faster.
> 
> Yes, there is some improvement, but I still seek a *factor* of 3 to 4
> overall before cpio+gzip.  All the slow coding persists.
> 
> 
> $ time /abs/path/to/dracut-013/dracut --local --force test2.img ### 
> [fixed-width font, please]   contrast to dracut-011
>    real  59s                           +3s user  26s                    
>          +6s sys   29s                           -2s
> 
>      26.0MB  output image            + 11.1MB 69.0MB  unzipped          
>           + 28.0MB
>    1947      files listed by cpio    +328  files
>     483      .ko kernel modules      +116  modules
> 
> ## Note the results have gotten larger (time, bytes, files, modules). ##
> The input (and configuration) has evolved, too.
> 

Can you add -M to see which modules are loaded?

As a kdump developer, I worry more about the size of initramfs generated
by dracut, because we have very limited memory (usually 128M or 256M)
in the second kernel. So, the output of `lsinitrd test2.img` would
be helpful too.

Thanks.

Re: building initramfs is slow

[Harald Hoyer]

On 19.08.2011 06:53, WANG Cong wrote:
> On Thu, 18 Aug 2011 16:09:19 -0700, John Reiser wrote:
> 
>> On 08/18/2011 11:25 AM, Harald Hoyer wrote:
>>> Try dracut version 013. It's already faster.
>>
>> Yes, there is some improvement, but I still seek a *factor* of 3 to 4
>> overall before cpio+gzip.  All the slow coding persists.
>>
>>
>> $ time /abs/path/to/dracut-013/dracut --local --force test2.img ### 
>> [fixed-width font, please]   contrast to dracut-011
>>    real  59s                           +3s user  26s                    
>>          +6s sys   29s                           -2s
>>
>>      26.0MB  output image            + 11.1MB 69.0MB  unzipped          
>>           + 28.0MB
>>    1947      files listed by cpio    +328  files
>>     483      .ko kernel modules      +116  modules
>>
>> ## Note the results have gotten larger (time, bytes, files, modules). ##
>> The input (and configuration) has evolved, too.
>>
> 
> Can you add -M to see which modules are loaded?
> 
> As a kdump developer, I worry more about the size of initramfs generated
> by dracut, because we have very limited memory (usually 128M or 256M)
> in the second kernel. So, the output of `lsinitrd test2.img` would
> be helpful too.
> 
> Thanks.

Maybe you should build your kdump kernel with the "hostonly" option, which will
significantly reduce your initramfs.

Re: building initramfs is slow

[Américo Wang]

On Fri, Aug 19, 2011 at 2:47 PM, Harald Hoyer <harald-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:
> On 19.08.2011 06:53, WANG Cong wrote:
>> As a kdump developer, I worry more about the size of initramfs generated
>> by dracut, because we have very limited memory (usually 128M or 256M)
>> in the second kernel. So, the output of `lsinitrd test2.img` would
>> be helpful too.
>>
>> Thanks.
>
> Maybe you should build your kdump kernel with the "hostonly" option, which will
> significantly reduce your initramfs.
>

Yeah, that does help, but the size is still large, see below

[root@nec-em18 ~]# dracut -H -M -f test.img --force-add nfs
dash
i18n
rpmversion
network
ifcfg
plymouth
dm
kernel-modules
lvm
nfs
resume
rootfs-block
terminfo
udev-rules
biosdevname
base
fs-lib
shutdown
[root@nec-em18 ~]# ls -lh test.img
-rw-r--r--. 1 root root 11M Aug 19 03:00 test.img

Also note, there are still some unneeded modules get included, e.g. i18n
and plymouth.

Therefore, I choose to use -m and -a to specify the modules we really need.

Re: building initramfs is slow

[Harald Hoyer]

On 19.08.2011 09:04, Américo Wang wrote:
> On Fri, Aug 19, 2011 at 2:47 PM, Harald Hoyer <harald-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:
>> On 19.08.2011 06:53, WANG Cong wrote:
>>> As a kdump developer, I worry more about the size of initramfs generated
>>> by dracut, because we have very limited memory (usually 128M or 256M)
>>> in the second kernel. So, the output of `lsinitrd test2.img` would
>>> be helpful too.
>>>
>>> Thanks.
>>
>> Maybe you should build your kdump kernel with the "hostonly" option, which will
>> significantly reduce your initramfs.
>>
> 
> Yeah, that does help, but the size is still large, see below
> 
> [root@nec-em18 ~]# dracut -H -M -f test.img --force-add nfs
> dash
> i18n
> rpmversion
> network
> ifcfg
> plymouth
> dm
> kernel-modules
> lvm
> nfs
> resume
> rootfs-block
> terminfo
> udev-rules
> biosdevname
> base
> fs-lib
> shutdown
> [root@nec-em18 ~]# ls -lh test.img
> -rw-r--r--. 1 root root 11M Aug 19 03:00 test.img
> 
> Also note, there are still some unneeded modules get included, e.g. i18n
> and plymouth.
> 
> Therefore, I choose to use -m and -a to specify the modules we really need.

Absolutely! You don't want plymouth and shutdown for example in your kdump
initramfs :-)

Re: building initramfs is slow

[Dan Horák]

Harald Hoyer píše v Pá 19. 08. 2011 v 09:07 +0200: 
> On 19.08.2011 09:04, Américo Wang wrote:
> > On Fri, Aug 19, 2011 at 2:47 PM, Harald Hoyer <harald-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:
> >> On 19.08.2011 06:53, WANG Cong wrote:
> >>> As a kdump developer, I worry more about the size of initramfs generated
> >>> by dracut, because we have very limited memory (usually 128M or 256M)
> >>> in the second kernel. So, the output of `lsinitrd test2.img` would
> >>> be helpful too.
> >>>
> >>> Thanks.
> >>
> >> Maybe you should build your kdump kernel with the "hostonly" option, which will
> >> significantly reduce your initramfs.
> >>
> > 
> > Yeah, that does help, but the size is still large, see below
> > 
> > [root@nec-em18 ~]# dracut -H -M -f test.img --force-add nfs
> > dash
> > i18n
> > rpmversion
> > network
> > ifcfg
> > plymouth
> > dm
> > kernel-modules
> > lvm
> > nfs
> > resume
> > rootfs-block
> > terminfo
> > udev-rules
> > biosdevname
> > base
> > fs-lib
> > shutdown
> > [root@nec-em18 ~]# ls -lh test.img
> > -rw-r--r--. 1 root root 11M Aug 19 03:00 test.img
> > 
> > Also note, there are still some unneeded modules get included, e.g. i18n
> > and plymouth.
> > 
> > Therefore, I choose to use -m and -a to specify the modules we really need.
> 
> Absolutely! You don't want plymouth and shutdown for example in your kdump
> initramfs :-)

and maybe you can use --filesystems too,
http://fedora.danny.cz/arm/dracut.conf is an example of dracut config I
use for preparing size-limited initramfs images for my Fedora/ARM
devices


Dan

Re: building initramfs is slow

[John Reiser]

On 08/18/2011 09:53 PM, WANG Cong wrote:

> Can you add -M to see which modules are loaded?

I'm going to skip this because of other people's responses in the meantime.
About 450 of the 2363 *.ko kernel modules in Fedora 16 were loaded.
See also the histogram below.

> 
> As a kdump developer, I worry more about the size of initramfs generated
> by dracut, because we have very limited memory (usually 128M or 256M)
> in the second kernel. So, the output of `lsinitrd test2.img` would
> be helpful too.

Fedora releases, pre-releases, and Live media are readily available.
You should be able to download, install/boot, and experiment in half a day.
$(lsinitrd test2.img) is too long, so I've made a sorted histogram
of number files by directory, and include the beginning here.
[My quick-and-dirty methodology might have holes.]

    188 lib/kbd/consolefonts/
    120 lib/kbd/keymaps/i386/qwerty/
     88 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/net/
     88 lib64/
     63 lib/kbd/unimaps/
     62 lib/firmware/radeon/
     61 sbin/
     59 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/ata/
     55 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/scsi/
     48 lib/kbd/consoletrans/
     46 lib/modules/3.0.0-1.fc16.x86_64/kernel/crypto/
     44 lib/modules/3.0.0-1.fc16.x86_64/kernel/fs/
     40 usr/share/plymouth/themes/charge/
     39 lib/kbd/consolefonts/partialfonts/
     38 lib/modules/3.0.0-1.fc16.x86_64/kernel/fs/nls/
     29 bin/
     28 lib/firmware/
     25 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/
     24 usr/lib64/
     19 lib/kbd/keymaps/i386/include/
     19 etc/
     18 lib/modules/3.0.0-1.fc16.x86_64/
     18 lib/kbd/keymaps/i386/qwertz/
     18 lib64/multipath/
     17 lib/kbd/keymaps/mac/all/
     17 lib/dracut/hooks/cmdline/
     16 lib/kbd/keymaps/sun/
     15 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/usb/storage/
     15 lib/modules/3.0.0-1.fc16.x86_64/kernel/drivers/md/
     13 lib/udev/rules.d/
     12 lib/dracut/hooks/

-- 

Re: building initramfs is slow

[Harald Hoyer]

On 18.08.2011 20:18, John Reiser wrote:
> Building an initramfs is unreasonably slow.  On Fedora 16
> dracut-011 takes almost a minute when installing a new kernel:
>    real   56s
>    user   20s   \__   dracut is CPU bound, not I/O bound.
>    sys    31s   /
> The final "gzip -9" takes 12 seconds, and the cpio 1 second,
> which leaves 43 seconds for the rest of dracut.  That's a
> factor of 3 or 4 too long.  The output initramfs is 14.9MB
> (41MB unzipped) and contains 1619 files, including 367 .ko
> kernel modules.

Some general thoughts.

1. speed at initramfs creation time is not sooo important. Normally this is only
done once in a while and not every day. Boot speed is more important.

2. if you care about speed of creation and size of the initramfs, turn on
"hostonly" in /etc/dracut.conf


> Yes, I'm going to work on it.
> 

That's cool! I accept patches :-)

Re: building initramfs is slow

[Harald Hoyer]

[-- Attachment #1: Type: text/plain, Size: 2103 bytes --]

On 18.08.2011 20:18, John Reiser wrote:
> Building an initramfs is unreasonably slow.  On Fedora 16
> dracut-011 takes almost a minute when installing a new kernel:
>    real   56s
>    user   20s   \__   dracut is CPU bound, not I/O bound.
>    sys    31s   /


Another profiling approach with dracut >= 013:

$ git clone git://git.kernel.org/pub/scm/boot/dracut/dracut.git
$ cd dracut
$ ./dracut --profile --local --force /tmp/test2.img &>/tmp/profile.out
$ python profile.py 2>/dev/null  < /tmp/profile.out | head -10|sed 's#/.*/##g'
dracut-functions@287 24.6794755459
dracut-functions@864 19.2174339294
dracut-functions@286 12.4720790386
dracut-functions@284 12.4622004032
dracut-functions@285 12.3773012161
dracut-functions@326 7.45590758324
./dracut@653 6.62076878548
dracut-logger@334 6.58080339432
dracut-functions@315 6.04220032692
dracut-functions@863 4.97196722031


of course this method adds the time of the PS4 evaluation to every line. So if a
line is called often, the "date" call of
     PS4='+ $(date "+%s.%N") ${BASH_SOURCE}@${LINENO}: '
is added multiple times.
Maybe we could patch bash to output nice profiling information.

lines 284-287 are in inst_dir()
dracut-functions@287 24.6794755459
dracut-functions@286 12.4720790386
dracut-functions@284 12.4622004032
dracut-functions@285 12.3773012161

This could, of course, be optimized. See attached patch.

Before:
real	0m30.752s
user	0m30.682s
sys	0m14.275s

After:
real	0m29.717s
user	0m30.486s
sys	0m14.220s

profiling after the patch:
dracut-functions@864 18.7074279785
dracut-functions@326 7.28814554214
./dracut@654 6.65880942345
dracut-logger@334 6.25012993813
dracut-functions@279 6.23409557343
dracut-functions@315 5.92809057236
dracut-functions@863 4.807523489
dracut-functions@862 4.75765013695
dracut-functions@411 3.63905620575
dracut-functions@273 3.21366071701

This is filter_kernel_modules()
dracut-functions@864 18.7074279785
dracut-functions@863 4.807523489
dracut-functions@862 4.75765013695

This is "cp -pfL":
dracut-functions@326 7.28814554214

This is the cpio and compress call:
./dracut@654 6.65880942345


[-- Attachment #2: dracut-inst_dir.patch --]
[-- Type: text/plain, Size: 860 bytes --]

diff --git a/dracut-functions b/dracut-functions
index 241d89a..d7f2e5f 100755
--- a/dracut-functions
+++ b/dracut-functions
@@ -274,18 +274,18 @@ inst_dir() {
     local _oldifs="$IFS"
     local _part
     local _dir="$1"
-    IFS="/"
-    set -- $_dir
-    IFS=$_oldifs
-    _dir="$@"
+
+    # fast out
     [[ -e ${initdir}$_dir ]] && return 0
 
-    # iterate over parent directories
-    for _part in $_dir; do
-        [[ $_part ]] || continue
-        _file="$_file/$_part"
-        [[ -e ${initdir}$_file ]] && continue
+    _part=${_dir%/*}
+    while ! [[ -e "${initdir}${_part}" ]]; do
+        _dir="$_part $_dir"
+        _part=${_part%/*}
+    done
 
+    # iterate over parent directories
+    for _file in $_dir; do
         if [[ -L $_file ]]; then
             # create link as the original
             local target=$(readlink -f "$_file")