[src/trunk]: src Add a postprocessor to /etc/rc, which logs messages to /var/...

[apb <apb%NetBSD.org@localhost>]

details:   https://anonhg.NetBSD.org/src/rev/e3dec08bb5df
branches:  trunk
changeset: 747331:e3dec08bb5df
user:      apb <apb%NetBSD.org@localhost>
date:      Fri Sep 11 18:17:04 2009 +0000

description:
Add a postprocessor to /etc/rc, which logs messages to /var/run/rc.log,
and which can suppress output in silent mode.  Silent mode is enabled
via the new rc_silent variable, which defaults to a value that depends
on the kern.boothowto sysctl.

Part of the /etc/rc silent changes requested in PR 41946
and proposed in tech-userlevel.

diffstat:

 doc/CHANGES              |    5 +-
 etc/defaults/rc.conf     |   13 +-
 etc/rc                   |  382 ++++++++++++++++++++++++++++++++++++++++++++--
 etc/rc.subr              |  175 +++++++++++++++++++++-
 share/man/man5/rc.conf.5 |   30 +++-
 share/man/man8/rc.8      |   32 +++-
 share/man/man8/rc.subr.8 |  108 +++++++++++++-
 7 files changed, 719 insertions(+), 26 deletions(-)

diffs (truncated from 948 to 300 lines):

diff -r a27194d60069 -r e3dec08bb5df doc/CHANGES
--- a/doc/CHANGES       Fri Sep 11 18:14:58 2009 +0000
+++ b/doc/CHANGES       Fri Sep 11 18:17:04 2009 +0000
@@ -1,4 +1,4 @@
-# LIST OF CHANGES FROM LAST RELEASE:                   <$Revision: 1.1287 $>
+# LIST OF CHANGES FROM LAST RELEASE:                   <$Revision: 1.1288 $>
 #
 #
 # [Note: This file does not mention every change made to the NetBSD source tree.
@@ -389,3 +389,6 @@
        build.sh: Add a modules operation which builds kernel modules and
                installs them into DESTDIR. [jnemeth 20090907]
        sysctl(7): Add kern.boothowto variable.  [apb 20090911]
+       rc(8): Output is now logged to /var/run/rc.log.  A new rc_silent
+               option, enabled if the kernel is booted in silent mode,
+               suppresses output to the console.  [apb 20090911]
diff -r a27194d60069 -r e3dec08bb5df etc/defaults/rc.conf
--- a/etc/defaults/rc.conf      Fri Sep 11 18:14:58 2009 +0000
+++ b/etc/defaults/rc.conf      Fri Sep 11 18:17:04 2009 +0000
@@ -1,4 +1,4 @@
-#      $NetBSD: rc.conf,v 1.104 2009/07/25 16:20:10 mbalmer Exp $
+#      $NetBSD: rc.conf,v 1.105 2009/09/11 18:17:04 apb Exp $
 #
 # /etc/defaults/rc.conf --
 #      default configuration of /etc/rc.conf
@@ -26,6 +26,17 @@
 #
 #rc_fast_and_loose=YES
 
+# If rc_silent is true then /etc/rc will suppress most output to
+# the console.  The default is taken from the AB_SILENT flag passed
+# from the boot loader to the kernel in the boothowto(9) variable.
+#
+# rc_silent_cmd is executed once for each suppressed line of output.
+# Useful values are ":" and "twiddle".
+#
+rc_silent=$( [ "$(( $(/sbin/sysctl -n kern.boothowto 2>/dev/null || echo 0) \
+                   & 0x40000 ))" != 0 ] && echo true || echo false )
+rc_silent_cmd=twiddle
+
 # Additional flags to the rcorder(8) that's run by /etc/rc.
 #
 rc_rcorder_flags=""
diff -r a27194d60069 -r e3dec08bb5df etc/rc
--- a/etc/rc    Fri Sep 11 18:14:58 2009 +0000
+++ b/etc/rc    Fri Sep 11 18:17:04 2009 +0000
@@ -1,9 +1,10 @@
 #!/bin/sh
 #
-# $NetBSD: rc,v 1.163 2009/04/10 16:18:04 joerg Exp $
+# $NetBSD: rc,v 1.164 2009/09/11 18:17:04 apb Exp $
 #
 # rc --
-#      Run the scripts in /etc/rc.d with rcorder.
+#      Run the scripts in /etc/rc.d with rcorder, and log output
+#      to /var/run/rc.log.
 
 #      System startup script run by init(8) on autoboot or after single-user.
 #      Output and error are redirected to console by init, and the console
@@ -13,10 +14,16 @@
 export PATH=/sbin:/bin:/usr/sbin:/usr/bin
 umask 022
 
-. /etc/rc.subr
+if [ -e ./rc.subr ] ; then
+       . ./rc.subr # for testing
+else
+       . /etc/rc.subr
+fi
 . /etc/rc.conf
 _rc_conf_loaded=true
 
+: ${RC_LOG_FILE:="/var/run/rc.log"}
+
 if ! checkyesno rc_configured; then
        echo "/etc/rc.conf is not configured.  Multiuser boot aborted."
        exit 1
@@ -27,24 +34,363 @@
        rc_fast=yes     # run_rc_command(): do fast booting
 fi
 
-stty status '^T'
+#
+# Completely ignore INT and QUIT at the outer level.  The rc_real_work()
+# function should do something different.
+#
+trap '' INT QUIT
+
+#
+# This string will be used to mark lines of meta-data sent over the pipe
+# from the rc_real_work() function to the rc_postprocess() function.  Lines
+# not so marked are assumed to be output from rc.d scripts.
+#
+# This string is long and unique to ensure that it does not accidentally
+# appear in output from any rc.d script.  It must not contain any
+# characters that are special to glob expansion ('*', '?', '[', or ']').
+#
+rc_metadata_prefix="$0:$$:metadata:";
 
-#      Set shell to ignore SIGINT, but not children;
-#      shell catches SIGQUIT and returns to single user.
+# Child scripts may sometimes want to print directly to the original
+# stdout and stderr, bypassing the pipe to the postprocessor.  These
+# _rc_*_fd variables are private, shared with /etc/rc.subr, but not
+# intended to be used directly by child scripts.  (Child scripts
+# may use rc.subr's no_rc_postprocess function.)
+#
+_rc_original_stdout_fd=7; export _rc_original_stdout_fd
+_rc_original_stderr_fd=8; export _rc_original_stderr_fd
+eval "exec ${_rc_original_stdout_fd}>&1"
+eval "exec ${_rc_original_stderr_fd}>&2"
+
+#
+# rc_real_work
+#      Do the real work.  Output from this function will be piped into
+#      rc_postprocess(), and some of the output will be marked as
+#      metadata.
+#
+# The body of this function is defined using (...), not {...}, to force
+# it to run in a subshell.
 #
-trap : INT
-trap "echo 'Boot interrupted.'; exit 1" QUIT
+rc_real_work()
+(
+       stty status '^T'
+
+       # print_rc_metadata() wants to be able to print to the pipe
+       # that goes to our postprocessor, even if its in a context
+       # with redirected output.
+       #
+       _rc_postprocessor_fd=9 ; export _rc_postprocessor_fd
+       eval "exec ${_rc_postprocessor_fd}>&1"
+
+       # Print a metadata line when we exit
+       #
+       trap 'es=$?; print_rc_metadata "exit:$es"; trap "" 0; exit $es' 0
+
+       #       Set shell to ignore SIGINT, but children will not ignore it.
+       #       Shell catches SIGQUIT and returns to single user.
+       #
+       trap : INT
+       trap '_msg="Boot interrupted at $(date)";
+             print_rc_metadata "interrupted:${_msg}";
+             exit 1' QUIT
+
+       print_rc_metadata "start:$(date)"
+
+       #
+       # The stop_boot() function in rc.subr may kill $RC_PID.  We want
+       # it to kill the subshell running this rc_real_work() function,
+       # rather than killing the parent shell, because we want the
+       # rc_postprocess() function to be able to log the error
+       # without being killed itself.
+       #
+       # "$$" is the pid of the top-level shell, not the pid of the
+       # subshell that's executing this function.  The command below
+       # tentatively assumes that the parent of the "/bin/sh -c ..."
+       # process will be the current subshell, and then uses "kill -0
+       # ..." to check the result.  If the "/bin/sh -c ..." process
+       # fails, or returns the pid of an ephemeral process that exits
+       # before the "kill" command, then we fall back to using "$$".
+       #
+       RC_PID=$(/bin/sh -c 'ps -p $$ -o ppid=') || RC_PID=$$
+       kill -0 $RC_PID >/dev/null 2>&1 || RC_PID=$$
+
+       #
+       # Get a list of all rc.d scripts, and use rcorder to choose
+       # what order to execute them.
+       #
+       # For testing, allow RC_FILES_OVERRIDE from the environment to
+       # override this.
+       #
+       print_rc_metadata "cmd-name:rcorder"
+       scripts=$(for rcd in ${rc_directories:-/etc/rc.d}; do
+               test -d ${rcd} && echo ${rcd}/*;
+       done)
+       files=$(rcorder -s nostart ${rc_rcorder_flags} ${scripts})
+       print_rc_metadata "cmd-status:rcorder:$?"
+
+       if [ -n "${RC_FILES_OVERRIDE}" ]; then
+               files="${RC_FILES_OVERRIDE}"
+       fi
+
+       #
+       # Run the scripts in order.
+       #
+       for _rc_elem in $files; do
+               print_rc_metadata "cmd-name:$_rc_elem"
+               run_rc_script $_rc_elem start
+               print_rc_metadata "cmd-status:$_rc_elem:$?"
+       done
 
-date
+       print_rc_metadata "end:$(date)"
+       exit 0
+)
+
+#
+# rc_postprocess
+#      Post-process the output from the rc_real_work() function.  For
+#      each line of input, we have to decide whether to print the line
+#      to the console, print a twiddle on the console, print a line to
+#      the log, or some combination of these.
+#
+#      If rc_silent is true, then suppress most output, instead running
+#      rc_silent_cmd (typically "twiddle") for each line.
+#
+# The body of this function is defined using (...), not {...}, to force
+# it to run in a subshell.
+#
+# We have to deal with the following constraints:
+#
+#  * There may be no writable file systems early in the boot, so
+#    any use of temporary files would be problematic.
+#
+#  * Scripts run during the boot may clear /tmp and/var/run, so even
+#    if they are writable, using those directories too early may be
+#    problematic.  We assume that it's safe to write to our log file
+#    after the mountcritlocal script has run.
+#
+#  * /usr/bin/tee cannot be used because the /usr file system may not
+#    be mounted early in the boot.
+#
+#  * All calls to the rc_log_message and rc_log_flush functions must be
+#    from the same subshell, otherwise the use of a shell variable to
+#    buffer log messages will fail.
+#
+rc_postprocess()
+(
+       local line
+       local before after
+       local IFS=''
+
+       # Try quite hard to flush the log to disk when we exit.
+       trap 'es=$?; rc_log_flush FORCE; trap "" 0; exit $es' 0
+
+       yesno_to_truefalse rc_silent 2>/dev/null
+
+       while read -r line ; do
+               case "$line" in
+               "${rc_metadata_prefix}"*)
+                       after="${line#*"${rc_metadata_prefix}"}"
+                       rc_postprocess_metadata "${after}"
+                       ;;
+               *"${rc_metadata_prefix}"*)
+                       # magic string is present, but not at the start of
+                       # the line.  Treat it like two separate lines.
+                       before="${line%"${rc_metadata_prefix}"*}"
+                       rc_postprocess_plain_line "${before}"
+                       after="${line#*"${rc_metadata_prefix}"}"
+                       rc_postprocess_metadata "${after}"
+                       ;;
+               *)
+                       rc_postprocess_plain_line "${line}"
+                       ;;
+               esac
+       done
+
+       # If we get here, then the rc_real_work() function must have
+       # exited uncleanly.  A clean exit would have been accompanied by
+       # a line of metadata that would have prevented us from getting
+       # here.
+       #
+       exit 1
+)
 
-scripts=$(for rcd in ${rc_directories:-/etc/rc.d}; do
-       test -d ${rcd} && echo ${rcd}/*;
-done)
-files=$(rcorder -s nostart ${rc_rcorder_flags} ${scripts})
+#
+# rc_postprocess_plain_line string
+#      $1 is a string representing a line of output from one of the
+#      rc.d scripts.  Append the line to the log, and also either
+#      display the line on the console, or run $rc_silent_cmd,
+#      depending on the value of $rc_silent.
+#
+rc_postprocess_plain_line()
+{
+       local line="$1"
+       rc_log_message "${line}"
+       if $rc_silent; then
+               eval "$rc_silent_cmd"
+       else
+               printf "%s\n" "${line}"
+       fi
+}
+
+#
+# rc_postprocess_metadata string
+#      $1 is a string containing metadata from the rc_real_work()
+#      function.  The rc_metadata_prefix marker should already
+#      have been removed before the string is passed to this function.
+#      Take appropriate action depending on the content of the string.
+#
+rc_postprocess_metadata()
+{
+       local metadata="$1"
+       local keyword args