timing partial booting from tc-config?

[nick65go]

Code: [Select]

tc@box:/lib$ cat /etc/init.d/tc-config | tail -n 5
if [ -n "$PAUSE" ]; then
        echo -n "${BLUE}Boot time configuration completed. Press <Enter> to continue.${NORMAL}"
        read junk
fi
could you let the user know the time (in seconds) spent booting? something like:

Code: [Select]

if [ -n "$PAUSE" ]; then
        time=`cat /proc/uptime | cut -d. -f1`
        echo -n "${BLUE}Boot time configuration completed in $time seconds. Press <Enter> to continue.${NORMAL}"
        read junk
fi

[curaga]

I'm a bit on the fence. printk.time=1 can be used to get more accurate boot time reporting on each step.

[nick65go]

anything you wish to add is OK for me. either /proc/uptime or printk.time etc
I am "studing" core.gz booting, for learning purposes and to provide feed-back.
on my real machine (with onboot.lst + small mydata.gz) it boots in min.18 - max.33 seconds.
for now "quick and dirty" i run in qemu, and core.gz boots in 3 seconds!!

Code: [Select]

#!/bin/sh
# on host do: sudo modprobe kvm-amd
#
# -machine: pc=Standard PC (i440FX + PIIX, 1996) (default), q35=Standard PC (Q35 + ICH9, 2009)
# -cpu max: Enables all features supported by the accelerator in the current host
#
arch=64

qemu-system-x86_64 -accel kvm -machine q35 -cpu max -m 1G\
 -kernel /mnt/sda10/boot/tc11/vmlinuz$arch \
 -initrd /mnt/sda10/boot/tc11/modules$arch.gz \
 -initrd /tmp/rootfs$arch.gz \
 -append pausei must overcome a small problem in qemu. (for rootfs.gz is OK, but for rootfs64.gz i manually created the folder 5.4.3-tinycore64 in /lib/modules/ to work; no big deal).

PS: if you would like to attach here your (even unfinished/unpolished) timing script for each step/case of tc-config, it will be great. thanks.

EDIT: changed my script last line, but IMHO it helps only for kernel log (using dmesg).

Code: [Select]

-append "pause printk.time=1"

[nick65go]

a possible solution, shameless inspired by /init logic, is to have a "timer" boot parametrer (like multivt)
in /etc/init.d/rcS

Code: [Select]

grep -qw timer /proc/cmdline && sed -i s/^#echo timer/echo timer/ /etc/init.d/tc-config
in /etc/init.d/tc-config

Code: [Select]

#echo "timer=`cat /proc/uptime` used sec.
MSSG="${BLUE}Loading extensions...${NORMAL}""inserted many times at start code lines, activated only on-demand by "timer" boot parameter?

[nick65go]

i need to work a little harder on regular expression for sed, because "space" char [ ] or \s is not OK.

Code: [Select]

tc@box:/mnt/sda10/Jail/build$ cat ./test.txt
#echo timer=john
#echo timer=Smith
tc@box:/mnt/sda10/Jail/build$ sed  -i s/^#echo\\stimer/echo\ timer/ ./test.txt
tc@box:/mnt/sda10/Jail/build$ cat ./test.txt
echo timer=john
echo timer=Smith
tc@box:/mnt/sda10/Jail/build$ yes! i got it now: sed  -i s/^#echo\\stimer/echo\ timer/
Edit: actually is even easier(space is back-quoted space"\ "): sed  -i s/^#echo\ timer/echo\ timer/

[curaga]

With printk.time=1 in bootcodes, you will know exactly when each modprobe call and similar happened. To time other arbitrary parts of tc-config you can insert calls to logger IIRC.

[nick65go]

"can insert calls to logger IIRC" ? I do not know how to do it.in the mean time I reinvented the wheel, again, using repeating similar code like

Code: [Select]

echo timer=`cat /proc/uptime` used sec. [6] Finish USB detection >> /tmp/timer.lstbecause virgin core.gz boot too fast (4 seconds in qemu), i simulated without "accel=kvm" so see the impact of tc-config sections.
now the boot time is 126 seconds, so i can see where there are the "possible" bottle-necks.Snapshot are attached, taken with grabber.tcz
summary: near 17% (=21/126) used before tc-config start,  51% [=80-29)/126] for zRAM

[Rich]

Hi nick65go

"can insert calls to logger IIRC" ? I do not know how to do it. ...

Add the boot code  syslog  to your bootloaders config file. Then add a time stamped message like this:

Code: [Select]

logger [6] Finish USB detectionYour message will show up in:

Code: [Select]

/var/log/messagesif that file filled up, the earlier messages will be in:

Code: [Select]

/var/log/messages.0

[nick65go]

Hi Rich,The boot code "syslog" is not so usefully, because it starts later in the "middle" of tc-config.
So, if you (download and) look into my previous attachment, you wiill see something like section

Code: [Select]

[10] Finish starting hostname, syslog + klog my demo is fully reproducible, if you want, I attached the "original" tc-config, with just my timers inserted. so it was about "28 sections".Anyway, thanks for your explanation, it can be useful to me in few other cases to try it.

[Greg Erskine]

Hi nick65go,

I use this command in startup scripts to write messages to dmesg.

$ sudo su -c 'echo "Starting xxxx." > /dev/kmsg'

The timestamping is automatic and it shows you when it is happening compared with the other startup processes.

I don't know if it is better than what you are doing, just another option.

regards
Greg

[nick65go]

i continue to eat my poison pill...and i am worried about: to do mistakes means to be human, to persevere in error is stupid.
so, i did a small back of the evelope calculation, about how much wasting time booting linux in a year's time:
1. booting 8 times/day ; because (24 h/day -8 h_sleep)/2h_battery_max_time =8
2. lets assume a gain of 4 seconds/boot; play with this variable later
3. "work" of 365 day/year (because linux addiction, no catch a illness, no holidays without computer, really?)

it means 4 x 8 x 365 =11680 sec/year, or 11680/(60 x 60)= 3.2 hours/year.
so if I spend 3 hours/year to shave 4 sec/boot then I got nothing, it is break even, or worst.
summary: it is all about hobby, not practical things to take pride of.
PS: I did a similar calculation about money (in another post) and it seams that for 3 hours/year "work for money" i will get paid with a free laptop. wow, so many variable.