From 7f44b79a9fe482d223b254b7ab260fbbfee4c822 Mon Sep 17 00:00:00 2001 From: classabbyamp Date: Wed, 4 Sep 2024 10:16:11 -0400 Subject: [PATCH 1/2] 1, 2, functions: instrument the boot process we can save boot timing information with good accuracy to the kernel message log, then retrieve it later with a script. --- 1 | 9 +++++++-- 2 | 5 +++++ functions | 4 ++++ 3 files changed, 16 insertions(+), 2 deletions(-) diff --git a/1 b/1 index 5a8c9a4..3e84af1 100755 --- a/1 +++ b/1 @@ -11,8 +11,13 @@ msg "Welcome to Void!" # Start core services: one-time system tasks. detect_virt -for f in /etc/runit/core-services/*.sh; do - [ -r $f ] && . $f +for cs in /etc/runit/core-services/*.sh; do + if [ -r "$cs" ]; then + kmsg "start:core:$cs" + . "$cs" + kmsg "finish:core:$cs" + fi done +kmsg "finish:core" msg "Initialization complete, running stage 2..." diff --git a/2 b/2 index 0a39298..b325e52 100755 --- a/2 +++ b/2 @@ -3,6 +3,8 @@ PATH=/usr/bin:/usr/sbin +. /etc/runit/functions + runlevel=default for arg in $(cat /proc/cmdline); do if [ -d /etc/runit/runsvdir/"$arg" ]; then @@ -11,11 +13,14 @@ for arg in $(cat /proc/cmdline); do fi done +kmsg "start:rclocal" [ -x /etc/rc.local ] && /etc/rc.local +kmsg "finish:rclocal" runsvchdir "${runlevel}" mkdir -p /run/runit/runsvdir ln -s /etc/runit/runsvdir/current /run/runit/runsvdir/current +kmsg "start:runsvdir" exec env - PATH=$PATH \ runsvdir -P /run/runit/runsvdir/current 'log: ...........................................................................................................................................................................................................................................................................................................................................................................................................' diff --git a/functions b/functions index ec961fc..1eb7e39 100644 --- a/functions +++ b/functions @@ -1,5 +1,9 @@ # *-*-shell-*-* +kmsg() { + printf "<7>runit: $@\n" >/dev/kmsg +} + msg() { # bold printf "\033[1m=> $@\033[m\n" From 775551677895814ce95bedb78005f5a731d12903 Mon Sep 17 00:00:00 2001 From: classabbyamp Date: Wed, 4 Sep 2024 10:17:49 -0400 Subject: [PATCH 2/2] runit-startuptime: new script parse the timing info from dmesg to give uses a rough accounting of time spent during boot. this may fail to be accurate if run a long time from boot (i.e. if the messages have left the kernel message ring buffer) --- Makefile | 2 ++ runit-startuptime | 69 +++++++++++++++++++++++++++++++++++++++++++++ runit-startuptime.1 | 42 +++++++++++++++++++++++++++ 3 files changed, 113 insertions(+) create mode 100755 runit-startuptime create mode 100644 runit-startuptime.1 diff --git a/Makefile b/Makefile index 0aa219a..a060e26 100644 --- a/Makefile +++ b/Makefile @@ -16,11 +16,13 @@ install: install -m755 modules-load ${DESTDIR}/${PREFIX}/sbin/modules-load install -m755 seedrng ${DESTDIR}/${PREFIX}/sbin/seedrng install -m755 zzz ${DESTDIR}/${PREFIX}/sbin + install -m755 runit-startuptime ${DESTDIR}/${PREFIX}/sbin ln -sf zzz ${DESTDIR}/${PREFIX}/sbin/ZZZ ln -sf halt ${DESTDIR}/${PREFIX}/sbin/poweroff ln -sf halt ${DESTDIR}/${PREFIX}/sbin/reboot install -d ${DESTDIR}/${PREFIX}/share/man/man1 install -m644 pause.1 ${DESTDIR}/${PREFIX}/share/man/man1 + install -m644 runit-startuptime.1 ${DESTDIR}/${PREFIX}/share/man/man1 install -d ${DESTDIR}/${PREFIX}/share/man/man8 install -m644 zzz.8 ${DESTDIR}/${PREFIX}/share/man/man8 install -m644 shutdown.8 ${DESTDIR}/${PREFIX}/share/man/man8 diff --git a/runit-startuptime b/runit-startuptime new file mode 100755 index 0000000..4b7f17e --- /dev/null +++ b/runit-startuptime @@ -0,0 +1,69 @@ +#!/bin/sh +# vim: set ts=4 sw=4 et ft=awk: + +if [ -n "$1" ]; then + printf "Usage: runit-startuptime\n\nPrint a rough accounting of where time is spent during boot\n" >&2 + exit 1 +fi + +dmesg -l debug | LANG=C.UTF-8 awk -F '[][ :]+' ' +BEGIN { + PROCINFO["sorted_in"] = "@ind_str_asc" + initramfs = 0 + coresvtotal = 0 + rclocal = 0 + total = 0 +} + +function svbasename(file) { + sub(".*/", "", file) + sub(".sh$", "", file) + return file +} + +$3 == "/init" { + initramfs = $2 + next +} + +$3 == "runit" { + if ($5 == "core") { + sv = svbasename($6) + if ($4 == "start") { + coresv[sv] = $2 + if (coresvtotal == 0) + coresvtotal = $2 + } else if ($4 == "finish") { + if ($6 != "") { + if (sv in coresv) + coresv[sv] = $2 - coresv[sv] + else + # /dev is not guaranteed until 00-pseudofs + # so the first start message may not exist + coresv[sv] = $2 - initramfs + } else + if (coresvtotal == 0) + coresvtotal = $2 - initramfs + else + coresvtotal = $2 - coresvtotal + } + } else if ($5 == "rclocal") { + if ($4 == "start") + rclocal = $2 + else if ($4 == "finish") + rclocal = $2 - rclocal + } else if ($5 == "runsvdir") + total = $2 + next +} + +END { + if (NR > 2) { + printf "initramfs\t%0.3f s\n", initramfs + printf "core-services\t%0.3f s\n", coresvtotal + for (sv in coresv) + printf " %-20s\t%0.3f s\n", sv, coresv[sv] + printf "rc.local\t%0.3f s\n", rclocal + printf "total\t\t%0.3f s\n", total + } +}' diff --git a/runit-startuptime.1 b/runit-startuptime.1 new file mode 100644 index 0000000..9e4be86 --- /dev/null +++ b/runit-startuptime.1 @@ -0,0 +1,42 @@ +.Dd September 4, 2024 +.Dt RUNIT-STARTUPTIME 1 +.Os +.Sh NAME +.Nm runit-startuptime +.Nd Print a rough accounting of where time is spent during boot +.Sh SYNOPSIS +.Nm runit-startuptime +.Sh DESCRIPTION +Void's runit init scripts print messages to the kernel message buffer at startup, +marking when some procedures start and finish. +.Nm +prints a rough accounting of where time is spent during boot using these messages. +.Nm +may require superuser privileges to read from dmesg. +The total time listed may not equal the sum of the other times, +because it does not track the timing of every moment of the boot process. +.Sh EXAMPLES +.Bd -literal +# runit-startuptime +initramfs 0.646 s +core-services 4.002 s + 00-pseudofs 0.056 s + 01-static-devnodes 1.178 s + 02-kmods 0.027 s + 02-udev 2.413 s + 03-console-setup 0.096 s + 03-filesystems 0.202 s + 04-swap 0.004 s + 05-misc 0.015 s + 08-sysctl 0.008 s + 20-screen 0.001 s + 98-sbin-merge 0.000 s + 99-cleanup 0.001 s +rc.local 0.002 s +total 7.952 s +.Ed +.Sh SEE ALSO +.Xr runit-init 8 +.Sh AUTHOR +.An classabbyamp , +.Mt void@placeviolette.net .