Monitoring Linux Boot Process


Would like to use run a SystemTap probe to see what the machine doing when it boots up like Bootchart, but allow more flexibility.

Techniques to create a SystemTap probe that runs at boot time were created for the One Laptop Per Child project, However, going through the steps can be a tedious. The boottap script used in this wiki entry was created to automate the process of converting the SystemTap script into a module and making a grub entry that can be selected when booting the machine. The boottap script also has an option to remove the script.

A ThinkPad T41 (a 1.6GHz Pentium M processors) running FC6 and the 2.6.18-1.2869.fc6 kernel, was setup to do some experiments to look at the bootup process. A simple script, iotime.stp, recorded the amount of wallclock time spent in reads and writes system calls was run. The script also recorded the amount of data that a process read or wrote that a process wrote to a file. The script was installed using boottap script:

./boottap -c /boottap15 -e 'sleep 100' -s /home/wcohen/iotime.stp

The "-c" creates the /boottap15 directory with the needed initscript and kernel module. The "-e" is an optional exit condition that shutsdown the instrumentation when the function returns. The "-s" is followed by the SystemTap script. The machine was rebooted and the grub entry for the boottap probe was selected. Once the script exits there is data in /boottap15/data/initprocs.log. This can be copied and examined for further analysis.


boottap iotime.stp


455 358 (sh) access /etc/ read: 0 write: 0
529 358 (sh) access /lib/ read: 512 write: 0
533 358 (sh) iotime /lib/ time: 5
586 358 (sh) access /lib/ read: 512 write: 0
589 358 (sh) iotime /lib/ time: 4
638 358 (sh) access /lib/ read: 512 write: 0
642 358 (sh) iotime /lib/ time: 3


One of the things that became clear when looking through the output was that modprobe does a linear search through the 250K modules.dep file each time it installs a module. The list is unordered and some of the seraches can require most of the list to be searched.

A very simple script was written to pre-pend the list of modules found with lsmod at the beginning of the file.

# A simple little script to generate prepend the list of modules 
# dependencies to the beginning of the list. This is a simple
# attempt to speed up the modprobe on bootup.

MODULES_DEP=/lib/modules/`uname -r`/modules.dep

#find the list of modules currently installed
used_modules=`/sbin/lsmod|awk  '{print $1}' | tr "_" "."`

for m in $used_modules; do
        grep "$m\.ko:" $MODULES_DEP


Installing the revised modules.dep file reduced the amount of /lib/modules/2.6.18-1.2869.fc6/modules.dep data read (and processed) by modprobe from 28.1MB to 20MB, as computed with a one-line script similar to the one below. The wallclock time spent in read systemtcalls for modules.dep dropped from 8.5seconds to 6.9seconds.

grep modules.dep normal-iotime20070126.log |grep access |awk 'BEGIN { rsum = 0 } { rsum += $7 } END { print rsum }'

The savings of this optimization was modest, only a couple of seconds out of nearly a minute for booting. However, it demonstrates the analysis of the Linux boot process and other systemtap scripts could be used to analyze other problems, e.g. which executables page fault.


None: WSBootTap (last edited 2008-01-10 19:47:29 by localhost)