[arch-projects] [mkinitcpio] [PATCH] Add options for logging of early userspace
This introduces support for the rd.log and rd.debug kernel command line options, which log early userspace activity to /run/initramfs/init.log.
Code is largely inspired by Dracut's implementation of early userspace logging, but without needless complexity and redundancies.
Signed-off-by: Dave Reisner dreisner@archlinux.org --- init | 5 ++ init_functions | 147 +++++++++++++++++++++++++++++++++++++++++++++------ install/base | 2 +- man/mkinitcpio.8.txt | 25 +++++++++ 4 files changed, 162 insertions(+), 17 deletions(-)
diff --git a/init b/init index dfebd53..7859aa3 100644 --- a/init +++ b/init @@ -19,6 +19,9 @@ mkdir -m755 /run/initramfs # parse the kernel command line parse_cmdline </proc/cmdline
+# setup logging as early as possible +rdlogger_start + for d in ${disablehooks//,/ }; do [ -e "/hooks/$d" ] && chmod 644 "/hooks/$d" done @@ -72,6 +75,8 @@ if [ "${break}" = "postmount" ]; then launch_interactive_shell fi
+rdlogger_stop + exec env -i \ "TERM=$TERM" \ "RD_TIMESTAMP=$RD_TIMESTAMP" \ diff --git a/init_functions b/init_functions index dc4361a..707f37c 100644 --- a/init_functions +++ b/init_functions @@ -1,5 +1,11 @@ # This file contains common functions used in init and in hooks
+# logging targets +_rdlog_file=$(( 1 << 0 )) +_rdlog_kmsg=$(( 1 << 1 )) +_rdlog_cons=$(( 1 << 2 )) +_rdlog_all=$(( (1 << 3) - 1 )) + msg () { [ "${quiet}" != "y" ] && echo $@ } @@ -41,6 +47,10 @@ launch_interactive_shell() { sh -i }
+bitfield_has_bit() { + [ $(( $1 & $2 )) -gt 0 ] +} + major_minor_to_device() { local dev
@@ -70,6 +80,30 @@ run_hookfunctions() { done }
+set_log_option() { + local opt words + + for opt in ${1//|/ }; do + case $opt in + all) + rd_log=$_rdlog_all + ;; + kmsg) + rd_log=$(( rd_log | _rdlog_kmsg )) + ;; + file) + rd_log=$(( rd_log | _rdlog_file )) + ;; + console) + rd_log=$(( rd_log | _rdlog_cons )) + ;; + *) + err "unknown rd.log parameter: '$opt'" + ;; + esac + done +} + parse_cmdline() { local _w _quoted _lhs _rhs _cmdline read -r _cmdline @@ -82,8 +116,25 @@ parse_cmdline() { rw|ro) rwopt=$_w ;; fsck.mode=*) case ${_w#*=} in - force) forcefsck=y ;; - skip) fastboot=y ;; + force) + forcefsck=y + ;; + skip) + fastboot=y + ;; + esac + ;; + rd.*) + case ${_w#rd.} in + debug) + rd_debug=1 + ;; + log) + rd_log=$_rdlog_all + ;; + log=*) + set_log_option "${_w#rd.log=}" + ;; esac ;; # abide by shell variable naming rules @@ -140,16 +191,10 @@ fsck_root() { fsck_device "$root" fsckret=$?
- fsck_ret() { - [ -z "$fsckret" ] && return 1 - [ "$fsckret" -eq "$1" ] && return 0 - [ "$(( fsckret & $1 ))" -eq "$1" ] - } - - if [ "$fsckret" -ne 255 ]; then - if [ "$fsckret" = '0' ] || fsck_ret 1; then + if [ -n "$fsckret" ] && [ "$fsckret" -ne 255 ]; then + if [ "$fsckret" = '0' ] || bitfield_has_bit $fsckret 1; then echo "$fsckret" > /run/initramfs/root-fsck - elif fsck_ret 4; then + elif bitfield_has_bit $fsckret 4; then err "Bailing out. Run 'fsck $root' manually" printf '%s\n' \ "********** FILESYSTEM CHECK FAILED **********" \ @@ -163,7 +208,7 @@ fsck_root() { echo ":: Automatic reboot in progress" sleep 2 reboot -f - elif fsck_ret 2; then + elif bitfield_has_bit $fsckret 2; then printf '%s\n' \ "************** REBOOT REQUIRED **************" \ "* *" \ @@ -172,13 +217,13 @@ fsck_root() { "*********************************************" sleep 10 reboot -f - elif fsck_ret 8; then + elif bitfield_has_bit $fsckret 8; then err "fsck failed on '$root'" - elif fsck_ret 16; then + elif bitfield_has_bit $fsckret 16; then err "Failed to invoke fsck: usage or syntax error" - elif fsck_ret 32; then + elif bitfield_has_bit $fsckret 32; then echo ":: fsck cancelled on user request" - elif fsck_ret 128; then + elif bitfield_has_bit $fsckret 128; then err "fatal error invoking fsck" fi fi @@ -254,4 +299,74 @@ default_mount_handler() { fi }
+rdlogger_start() { + [ -n "$rd_log" ] || return + mkfifo /run/initramfs/rdlogger.pipe + rdlogger </run/initramfs/rdlogger.pipe >/dev/console 2>&1 & + exec >/run/initramfs/rdlogger.pipe 2>&1 + [ -n "$rd_debug" ] && set -x +} + +rdlogger_stop() { + local i=0 + + [ -e /run/initramfs/rdlogger.pipe ] || return + + [ -n "$rd_debug" ] && { set +x; } 2>/dev/null + + # signal logger to exit by redirecting FDs back to /dev/console + exec 0<>/dev/console 1<>/dev/console 2<>/dev/console + + # wait up to 1 second for rdlogger to exit gracefully + while [ -e /run/initramfs/rdlogger.pipe ] && [ $i -lt 10 ]; do + sleep 0.1 + i=$(( i + 1 )) + done + + [ $i -eq 10 ] && kill %1 2>/dev/null +} + +rdlogger() { + local line + + # always cleanup on exit + trap 'rm -f /run/initramfs/rdlogger.pipe' EXIT + + # establish log targets. Either redirect to an appropriate file descriptor, + # or to /dev/null. This way, logging can Just Happen and the attached FD + # will Do The Right Thing™. + + # rd.log=kmsg + if [ -c /dev/kmsg ] && bitfield_has_bit "$rd_log" "$_rdlog_kmsg"; then + exec 5>/dev/kmsg + else + exec 5>/dev/null + fi + + # rd.log=file + if bitfield_has_bit "$rd_log" "$_rdlog_file"; then + exec 6>/run/initramfs/init.log + else + exec 6>/dev/null + fi + + # rd.log=console + if ! bitfield_has_bit "$rd_log" "$_rdlog_cons" || [ -n "$quiet" ]; then + exec >/dev/null + fi + + while read -r line; do + # rd.log=kmsg + printf '<31>initramfs: %s\n' "$line" >&5 + + # rd.log=file + printf '%s\n' "$line" >&6 + + # rd.log=console + printf '%s\n' "$line" + done + + # EOF, shutting down... +} + # vim: set ft=sh ts=4 sw=4 et: diff --git a/install/base b/install/base index ad0e5f2..397168f 100644 --- a/install/base +++ b/install/base @@ -3,7 +3,7 @@ build() { local applet
- add_binary /usr/lib/initcpio/busybox /bin/busybox + add_binary /usr/lib/initcpio/busybox /usr/bin/busybox
for applet in $(/usr/lib/initcpio/busybox --list); do add_symlink "/usr/bin/$applet" busybox diff --git a/man/mkinitcpio.8.txt b/man/mkinitcpio.8.txt index 56ac571..4f2db59 100644 --- a/man/mkinitcpio.8.txt +++ b/man/mkinitcpio.8.txt @@ -248,6 +248,31 @@ the kernel command line: device to show up, if it is not available immediately. This defaults to 5 seconds. If an invalid integer is passed, this variable will have no effect.
+*rd.debug*:: + Enables shell debug (xtrace). This option is only useful in combination with + the 'rd.log' option. + +*rd.log*['=<console|file|kmsg|all>']:: + Enables logging of early userspace messages. If specified, the optional + parameter describes where this information is logged. Multiple options can be + OR'd together using the pipe (|) character. Messages are always logged + to the console unless the 'quiet' parameter is passed. + + *console*;; + Writes log output to '/dev/console'. + + *file*;; + Writes log output to '/run/initramfs/init.log' + + *kmsg*;; + Writes output to the kernel ring buffer using the '/dev/kmsg' device + (introduced in Linux 3.5). This option is a no-op if your kernel does + not support this device. + + *all*;; + Writes output to all known log targets. This is the default if no option + is specified. + These are only the variables that the core of mkinitcpio honor. Additional hooks may look for other environment variables and should be documented by the help output for the hook.
On Tue, Jun 18, 2013 at 05:17:20PM -0400, Dave Reisner wrote:
This introduces support for the rd.log and rd.debug kernel command line options, which log early userspace activity to /run/initramfs/init.log.
Code is largely inspired by Dracut's implementation of early userspace logging, but without needless complexity and redundancies.
Signed-off-by: Dave Reisner dreisner@archlinux.org
init | 5 ++ init_functions | 147 +++++++++++++++++++++++++++++++++++++++++++++------ install/base | 2 +- man/mkinitcpio.8.txt | 25 +++++++++ 4 files changed, 162 insertions(+), 17 deletions(-)
[...] diff --git a/install/base b/install/base index ad0e5f2..397168f 100644 --- a/install/base +++ b/install/base @@ -3,7 +3,7 @@ build() { local applet
- add_binary /usr/lib/initcpio/busybox /bin/busybox
- add_binary /usr/lib/initcpio/busybox /usr/bin/busybox
Huh? Should this be done in a separate commit?
for applet in $(/usr/lib/initcpio/busybox --list); do add_symlink "/usr/bin/$applet" busybox[...]
On 18.06.2013 23:17, Dave Reisner wrote:
This introduces support for the rd.log and rd.debug kernel command line options, which log early userspace activity to /run/initramfs/init.log.
Code is largely inspired by Dracut's implementation of early userspace logging, but without needless complexity and redundancies.
Signed-off-by: Dave Reisner dreisner@archlinux.org
init | 5 ++ init_functions | 147 +++++++++++++++++++++++++++++++++++++++++++++------ install/base | 2 +- man/mkinitcpio.8.txt | 25 +++++++++ 4 files changed, 162 insertions(+), 17 deletions(-)
diff --git a/init b/init index dfebd53..7859aa3 100644 --- a/init +++ b/init @@ -19,6 +19,9 @@ mkdir -m755 /run/initramfs # parse the kernel command line parse_cmdline </proc/cmdline
+# setup logging as early as possible +rdlogger_start
for d in ${disablehooks//,/ }; do [ -e "/hooks/$d" ] && chmod 644 "/hooks/$d" done @@ -72,6 +75,8 @@ if [ "${break}" = "postmount" ]; then launch_interactive_shell fi
+rdlogger_stop
exec env -i \ "TERM=$TERM" \ "RD_TIMESTAMP=$RD_TIMESTAMP" \ diff --git a/init_functions b/init_functions index dc4361a..707f37c 100644 --- a/init_functions +++ b/init_functions @@ -1,5 +1,11 @@ # This file contains common functions used in init and in hooks
+# logging targets +_rdlog_file=$(( 1 << 0 )) +_rdlog_kmsg=$(( 1 << 1 )) +_rdlog_cons=$(( 1 << 2 )) +_rdlog_all=$(( (1 << 3) - 1 ))
msg () { [ "${quiet}" != "y" ] && echo $@ } @@ -41,6 +47,10 @@ launch_interactive_shell() { sh -i }
+bitfield_has_bit() {
- [ $(( $1 & $2 )) -gt 0 ]
+}
major_minor_to_device() { local dev
@@ -70,6 +80,30 @@ run_hookfunctions() { done }
+set_log_option() {
- local opt words
words is unused
- for opt in ${1//|/ }; do
case $opt inall)rd_log=$_rdlog_all;;kmsg)rd_log=$(( rd_log | _rdlog_kmsg ));;file)rd_log=$(( rd_log | _rdlog_file ));;console)rd_log=$(( rd_log | _rdlog_cons ));;*)err "unknown rd.log parameter: '$opt'";;esac- done
+}
parse_cmdline() { local _w _quoted _lhs _rhs _cmdline read -r _cmdline @@ -82,8 +116,25 @@ parse_cmdline() { rw|ro) rwopt=$_w ;; fsck.mode=*) case ${_w#*=} in
force) forcefsck=y ;;skip) fastboot=y ;;
force)forcefsck=y;;skip)fastboot=y;;esac;;
Above changes are out of scope, see somewhere below. (I'm jumping around while writing this mail)
They are also not documented in mkinitcpio(8) afaics. If they are some standard options documented elsewhere, ignore this.
They should probably also have an "unknown parameter" check like rd.log has.
rd.*)case ${_w#rd.} indebug)rd_debug=1;;log)rd_log=$_rdlog_all;;log=*)set_log_option "${_w#rd.log=}";; esac ;; # abide by shell variable naming rules@@ -140,16 +191,10 @@ fsck_root() { fsck_device "$root" fsckret=$?
- fsck_ret() {
[ -z "$fsckret" ] && return 1[ "$fsckret" -eq "$1" ] && return 0[ "$(( fsckret & $1 ))" -eq "$1" ]- }
- if [ "$fsckret" -ne 255 ]; then
if [ "$fsckret" = '0' ] || fsck_ret 1; then
- if [ -n "$fsckret" ] && [ "$fsckret" -ne 255 ]; then
if [ "$fsckret" = '0' ] || bitfield_has_bit $fsckret 1; then echo "$fsckret" > /run/initramfs/root-fsck
elif fsck_ret 4; then
elif bitfield_has_bit $fsckret 4; then err "Bailing out. Run 'fsck $root' manually" printf '%s\n' \ "********** FILESYSTEM CHECK FAILED **********" \@@ -163,7 +208,7 @@ fsck_root() { echo ":: Automatic reboot in progress" sleep 2 reboot -f
elif fsck_ret 2; then
elif bitfield_has_bit $fsckret 2; then printf '%s\n' \ "************** REBOOT REQUIRED **************" \ "* *" \@@ -172,13 +217,13 @@ fsck_root() { "*********************************************" sleep 10 reboot -f
elif fsck_ret 8; then
elif bitfield_has_bit $fsckret 8; then err "fsck failed on '$root'"
elif fsck_ret 16; then
elif bitfield_has_bit $fsckret 16; then err "Failed to invoke fsck: usage or syntax error"
elif fsck_ret 32; then
elif bitfield_has_bit $fsckret 32; then echo ":: fsck cancelled on user request"
elif fsck_ret 128; then
elif bitfield_has_bit $fsckret 128; then err "fatal error invoking fsck" fi
More out of scope changes.
@@ -254,4 +299,74 @@ default_mount_handler() { fi }
+rdlogger_start() {
- [ -n "$rd_log" ] || return
- mkfifo /run/initramfs/rdlogger.pipe
- rdlogger </run/initramfs/rdlogger.pipe >/dev/console 2>&1 &
- exec >/run/initramfs/rdlogger.pipe 2>&1
- [ -n "$rd_debug" ] && set -x
+}
+rdlogger_stop() {
- local i=0
- [ -e /run/initramfs/rdlogger.pipe ] || return
- [ -n "$rd_debug" ] && { set +x; } 2>/dev/null
- # signal logger to exit by redirecting FDs back to /dev/console
- exec 0<>/dev/console 1<>/dev/console 2<>/dev/console
- # wait up to 1 second for rdlogger to exit gracefully
- while [ -e /run/initramfs/rdlogger.pipe ] && [ $i -lt 10 ]; do
sleep 0.1i=$(( i + 1 ))- done
- [ $i -eq 10 ] && kill %1 2>/dev/null
Maybe use a variable for the pid or something more descriptive instead of %1? I'm a little worried this might break in the future if we ever have more than one job.
+}
+rdlogger() {
- local line
- # always cleanup on exit
- trap 'rm -f /run/initramfs/rdlogger.pipe' EXIT
- # establish log targets. Either redirect to an appropriate file descriptor,
- # or to /dev/null. This way, logging can Just Happen and the attached FD
- # will Do The Right Thing™.
- # rd.log=kmsg
- if [ -c /dev/kmsg ] && bitfield_has_bit "$rd_log" "$_rdlog_kmsg"; then
exec 5>/dev/kmsg- else
exec 5>/dev/null- fi
- # rd.log=file
- if bitfield_has_bit "$rd_log" "$_rdlog_file"; then
exec 6>/run/initramfs/init.log- else
exec 6>/dev/null- fi
- # rd.log=console
- if ! bitfield_has_bit "$rd_log" "$_rdlog_cons" || [ -n "$quiet" ]; then
exec >/dev/null- fi
- while read -r line; do
# rd.log=kmsgprintf '<31>initramfs: %s\n' "$line" >&5
"<31>"? kernel magic or something?
# rd.log=fileprintf '%s\n' "$line" >&6# rd.log=consoleprintf '%s\n' "$line"- done
- # EOF, shutting down...
+}
# vim: set ft=sh ts=4 sw=4 et: diff --git a/install/base b/install/base index ad0e5f2..397168f 100644 --- a/install/base +++ b/install/base @@ -3,7 +3,7 @@ build() { local applet
- add_binary /usr/lib/initcpio/busybox /bin/busybox
- add_binary /usr/lib/initcpio/busybox /usr/bin/busybox
And some more out of scope changes. I like (feature) patches that only really touch what they have to. Easier to understand and patchcount++ never hurts.
for applet in $(/usr/lib/initcpio/busybox --list); do add_symlink "/usr/bin/$applet" busyboxdiff --git a/man/mkinitcpio.8.txt b/man/mkinitcpio.8.txt index 56ac571..4f2db59 100644 --- a/man/mkinitcpio.8.txt +++ b/man/mkinitcpio.8.txt @@ -248,6 +248,31 @@ the kernel command line: device to show up, if it is not available immediately. This defaults to 5 seconds. If an invalid integer is passed, this variable will have no effect.
+*rd.debug*::
- Enables shell debug (xtrace). This option is only useful in combination with
- the 'rd.log' option.
I don't see the point of requiring users to set rd.log. If you set rd.debug you clearly want debugging stuff to be shown somewhere so I think setting rd.debug should set rd.log to at least console if it hasn't been set already.
+*rd.log*['=<console|file|kmsg|all>']::
- Enables logging of early userspace messages. If specified, the optional
- parameter describes where this information is logged. Multiple options can be
- OR'd together using the pipe (|) character. Messages are always logged
- to the console unless the 'quiet' parameter is passed.
- *console*;;
Writes log output to '/dev/console'.- *file*;;
Writes log output to '/run/initramfs/init.log'- *kmsg*;;
Writes output to the kernel ring buffer using the '/dev/kmsg' device(introduced in Linux 3.5). This option is a no-op if your kernel doesnot support this device.- *all*;;
Writes output to all known log targets. This is the default if no optionis specified.
better: "if no optional parameter is specified". "no option" sounds like if you don't add rd.log it will default to all.
These are only the variables that the core of mkinitcpio honor.
"honor" misses an s, but that's not in scope of that patch. Maybe someone should do a spelling/grammar check.
Additional
hooks may look for other environment variables and should be documented by the help output for the hook.
Assuming all this fd magic in start/stop works (didn't look at it and I saw that screenshot you posted yesterday so I just assume it does) I like the idea a lot.
participants (3)
-
Dave Reisner
-
Florian Pritz
-
Lukas Fleischer