[arch-general] howto trace userland startup

[clemens fischer]

It may so happen that one wants to know what's wrong with some
configuration, but it is handled at boot time and the initscripts don't
provide enough info.  An alternative is to use the hook functions
scattered about the initscripts, which may or may not be better for your
needs.

This is my trick to have certain scripts set to bash's trace mode and
leave output in a file.  It needs one configuration line in etc/rc.conf
and a file in etc/rc.d/functions.d/:

Example:

# /etc/rc.conf - Main Configuration for Arch Linux
...
only_info_pls="*@(/network|/iptables)*:::/root/system/boot/questions/!0-!1-!2.txt"
...

This will "trigger" when the name of the script executed matches either
*/network* or */iptables*, set them to trace mode "-x" and collect their
output in files named after the script's name, with "/" replaced by ":".
Each of "!0", "!1" .. "!5" undergo this substitution.  I get the
following files:

  $ ls -l /root/system/boot/questions/
  total 32K
  -rw-r--r-- 1 root root 1235 Feb 17 20:38 :etc:rc.d:iptables-start-.txt
  -rw-r--r-- 1 root root 4699 Feb 17 20:37 :etc:rc.d:iptables-stop-.txt
  -rw-r--r-- 1 root root 8802 Feb 17 20:39 :etc:rc.d:network-start-.txt
  -rw-r--r-- 1 root root 4827 Feb 17 20:37 :etc:rc.d:network-stop-.txt

The syntax of the variable $only_info_pls is like this:

  <matcher>:::<output>

where <matcher> is matched against the scripts name with bash option
extglob set before going to work and reset to its previous state
afterwards.  <output> defines a file on a filesystem that must be
mounted when the monitored script starts.  Occurrences of !<n> with <n>
from "0" ... "5" are expanded with the appropriate script arguments, and
directory separators are replaced with colons.

etc/rc.d/functions.d/only_info_pls.sh is too small to make anything more
than this post of it, but it proved very useful so far.  I tried to make
it safe to use even with matchers such as "*/rc.sysinit*" in that the
existence of logger(1) and /dev/null are checked before use, and
a missing <output> declaration defaults to "only_info_pls.sh-!0", which
dumps the trace into the current directory if its writable.


clemens


# /etc/rc.d/functions.d/only_info_pls.sh
# _date: 20100217-2035_
#
# to be sourced by bash(1).
# see /etc/rc.conf
# see /etc/rc.d/functions

_iam="/etc/rc.d/functions.d/only_info_pls.sh"

# global: ${only_info_pls} ${_only_info_pls_out}, ${_only_info_pls_trig},
# ${_only_info_pls_extglob}, ${_only_info_pls_logger}
# initscripts colors from /etc/rc.d/functions:
# global: $C_MAIN, $C_OTHER, $C_SEPARATOR, $C_BUSY, $C_FAIL, $C_DONE,
# $C_BKGD, $C_H1, $C_H2, $C_CLEAR, $SAVE_POSITION, $RESTORE_POSITION,
# $DEL_TEXT, $STAT_COL, $SECOLOR
_only_info_pls_prep()
{
    local out0="${0//\//:}"
    local cmd="${1:-prep}"
    local devnull="/dev/null"
    local out1
    local out2
    local out3
    local out4
    local out5
    shift
    #
    case "-${cmd}" in
        -prep)
            out1="${1//\//:}"
            out2="${2//\//:}"
            out3="${3//\//:}"
            out4="${4//\//:}"
            out5="${5//\//:}"
            _only_info_pls_trig="${only_info_pls%%:::*}"
            _only_info_pls_out="${only_info_pls##*:::}"
            : ${_only_info_pls_logger:="logger -s"}
            : ${_only_info_pls_out:="${_iam##*/}-!0"}
            _only_info_pls_out="${_only_info_pls_out/!0/${out0}}"
            _only_info_pls_out="${_only_info_pls_out/!1/${out1}}"
            _only_info_pls_out="${_only_info_pls_out/!2/${out2}}"
            _only_info_pls_out="${_only_info_pls_out/!3/${out3}}"
            _only_info_pls_out="${_only_info_pls_out/!4/${out4}}"
            _only_info_pls_out="${_only_info_pls_out/!5/${out5}}"
            [ -w "${devnull}" ] && {
                type -t "${_only_info_pls_logger%% *}" > ${devnull} ||
                _only_info_pls_logger="echo"
                :
            } || {
                type -t "${_only_info_pls_logger%% *}" ||
                _only_info_pls_logger="echo"
                :
            }
            _only_info_pls_extglob="-u"
            shopt -q extglob && _only_info_pls_extglob="-s"
            ;;
        -colors)
            C_MAIN=""      # main text
            C_OTHER=""     # prefix & brackets
            C_SEPARATOR="-" # separator
            C_BUSY=""      # busy
            C_FAIL=""      # failed
            C_DONE=""      # completed
            C_BKGD="<bg>"      # backgrounded
            C_H1=""        # highlight text 1
            C_H2=""        # highlight text 2
            C_CLEAR=""
            SAVE_POSITION=""; RESTORE_POSITION=""; DEL_TEXT=""
            STAT_COL=80; SECOLOR="neee"
            ;;
    esac
    return 0
}

# local hack: info instead of colors!
# implemented via /etc/rc.d/functions.d/only_info_pls.sh
# see /etc/rc.conf
#only_info_pls=""
#only_info_pls="*@(/network|/iptables)*:::/root/system/boot/questions/!0-!1-!2.txt"
#only_info_pls="*@(/network|/iptables)*:::/root/system/boot/questions/rc.d-network-!1.txt"
#only_info_pls="*/network*:::/root/system/boot/questions/rc.d-network-!1-!2.txt"
#
[ -n "${only_info_pls}" ] && {
    _only_info_pls_prep prep "$@"
    ${_only_info_pls_logger} "${_iam}: trigger='${_only_info_pls_trig}' out='${_only_info_pls_out}' \$0='$0' \$*='$*'"
    # debugging aid: match on both $0 and $1 to catch scripts
    shopt -s extglob
    case "${0}x${1}" in
        ${_only_info_pls_trig})
            _only_info_pls_prep colors "$@"
            [ -w "${_only_info_pls_out}" ] && exec >> "${_only_info_pls_out}" 2>&1
            echo
            echo "=== $(date '+%y%m%d-%H%M') ${_iam}: '${0}' '${*}'"
            echo
            set -x
            ;;
    esac
    shopt "${_only_info_pls_extglob}" extglob
}