[arch-projects] [mkinitcpio] [PATCH] Add options for logging of early userspace

Florian Pritz bluewind at xinu.at
Tue Jun 18 18:06:54 EDT 2013


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 at 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 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
> +                    ;;

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.} 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

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.1
> +        i=$(( 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=kmsg
> +        printf '<31>initramfs: %s\n' "$line" >&5

"<31>"? kernel magic or something?

> +
> +        # 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

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" 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.

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 does
> +		not support this device.
> +
> +	*all*;;
> +		Writes output to all known log targets. This is the default if no option
> +		is 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.


-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 836 bytes
Desc: OpenPGP digital signature
URL: <http://mailman.archlinux.org/pipermail/arch-projects/attachments/20130619/ddbfc564/attachment.asc>


More information about the arch-projects mailing list