During a fresh install from Fedora 17-Alpha-x86_64-DVD, and after all
packages have been installed, then there is a pause of a few minutes
before installation completes and is ready for Reboot. On a 2GHz box
I waited about 3 minutes from the last package before seeing "Bootloader
installation", and another 2 minutes before "Congratulations! ... Ready
for Reboot."
That five minutes from the last package to Reboot is much too long,
particularly without better indications of progress.
I re-ran the complete fresh install but turned on measuring near
the end of package install. On VT2 I entered the shell commands:
cd /mnt/sysimage/root # somewhere to keep a file
strace -f -t -o strace.out -e trace=file -p PID_of_anaconda 2>/dev/null
This traces the anaconda process and any future children, writes output
to a file, traces all system calls that involve filenames, and includes
the wall-clock time at each syscall.
When installation finished, then I applied text processing tools to
strace.out. Subtracting wall-clock times revealed these major steps
(and in this order):
seconds activity
112 dracut (construct initramfs)
260 new-kernel-pkg --rpmposttrans (commit yum transaction)
230 grub2-mkconfig (bootloader configuration)
65 anaconda (reset SELinux attributes of files in yum database)
=====
667 strace expanded wall-clock time by a factor of 2.2 (667/300)
I suggest that the activities "Construct initramfs", "Commit yum transaction",
and "Set SELinux attributes for yum database" deserve to be mentioned
separately just as "Bootloader configuration". It is curious that the
SELinux attributes for the yum database are not reset as part of the
--rpmposttrans, and that the bootloader configuration occurs between
those two activities.
The sorted histogram of all calls from strace.out begins:
81918 newfstatat(5 [gtk-update-icon-cache *.png, *.svg]
28648 --- {si_signo=SIGCHLD [total clone()]
22971 stat("/usr/bin/logger" [7288 execve() below]
21814 stat("/usr/bin/sed" [lack of 'bash' string processing]
20717 open("/etc/ld.so.cache" [total execve()]
20656 access("/etc/ld.so.preload"
19961 open("/lib64/libc.so.6"
17303 stat("/tmp/updates"
17303 stat("/tmp/product"
17297 stat("/tmp/updates/x86_64"
17297 stat("/tmp/updates/tls/x86_64"
17297 stat("/tmp/updates/tls"
17297 stat("/tmp/product/x86_64"
17297 stat("/tmp/product/tls/x86_64"
17297 stat("/tmp/product/tls"
15314 access("/usr/bin/logger"
14540 access("/usr/bin/sed"
13718 open("/dev/sde"
13383 open("/dev/sdb"
12708 statfs("/sys/fs/selinux"
11513 open("/sys/fs/selinux/context"
11368 lstat("/var"
11334 lstat("/var/lib"
11316 lstat("/var/lib/yum"
11134 stat("."
10487 open("/tmp/updates/libc.so.6"
10485 open("/tmp/updates/x86_64/libc.so.6"
10485 open("/tmp/updates/tls/x86_64/libc.so.6"
10485 open("/tmp/updates/tls/libc.so.6"
10485 open("/tmp/product/x86_64/libc.so.6"
10485 open("/tmp/product/tls/x86_64/libc.so.6"
10485 open("/tmp/product/tls/libc.so.6"
10485 open("/tmp/product/libc.so.6"
10141 newfstatat(4
10048 openat(4
9332 openat(5
9172 open("/dev/sdd"
7545 open("/dev/sda"
7459 stat("/usr/bin/grep"
7288 execve("/usr/bin/logger"
7278 open("/usr/share/zoneinfo/America/Los_Angeles"
7140 open("/lib64/libdl.so.2"
6396 stat("/usr/bin/cut"
6378 open("/lib64/libselinux.so.1"
One immediate suggestion: If the directories /tmp/updates and /tmp/product
contain no regular files [at any depth], then remove those directories
from the PATH and LD_LIBRARY_PATH environment variables. This will save
much searching.
All usage of /usr/bin/logger is within grub2-mkconfig. Could the logger be
run in parallel with items redirected into its stdin, instead invoking
a separate process each time?
The sorted histogram of filesystem probing via grub2-probe begins:
13718 open("/dev/sde"
13383 open("/dev/sdb"
9172 open("/dev/sdd"
7545 open("/dev/sda"
5129 open("/dev/sdb1"
4817 open("/dev/sdb2"
4337 open("/dev/sdb3"
4326 open("/dev/sde1"
4017 open("/dev/sde2"
4002 open("/dev/sdb5"
3904 open("/dev/sde4"
3857 open("/dev/sde3"
3689 open("/dev/sdb6"
3537 open("/dev/sdb7"
3521 open("/dev/sdb4"
3082 open("/dev/sdb9"
3057 open("/dev/sde5"
3057 open("/dev/sdb8"
3043 open("/dev/sdd1"
2737 open("/dev/sde6"
2444 open("/dev/sde8"
2417 open("/dev/sde7"
2417 open("/dev/sdd5"
2417 open("/dev/sdb10"
2416 open("/dev/sda1"
2296 open("/dev/null"
2257 open("/dev/sdb11"
2097 open("/dev/sdd6"
2094 open("/dev/sda2"
1921 open("/dev/sdd4"
1777 open("/dev/sde9"
1777 open("/dev/sdd8"
1777 open("/dev/sdd7"
1777 open("/dev/sdb12"
1767 open("/dev/sda3"
1457 open("/dev/sde10"
1457 open("/dev/sdb13"
1442 open("/dev/sda5"
1137 open("/dev/sdd9"
1137 open("/dev/sdb14"
1129 open("/dev/sda6"
1126 open("/dev/sde11"
1075 open("/dev/dm-0"
961 open("/dev/sda4"
960 open("/dev/sdd3"
960 open("/dev/sdd2"
831 open("/dev/sde12"
817 open("/dev/sdd10"
817 open("/dev/sda7"
806 open("/dev/sdb15"
This suggests that a quadratic algorithm is overstaying its welcome.
--
_______________________________________________
Anaconda-devel-list mailing list
Anaconda-devel-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/anaconda-devel-list
