[make-initrd] [PATCH v6 12/22] bootchain-core: introduces extended debugging

["Leonid Krivoshein" <klark.devel@gmail.com>]

Extends the bootchain-sh-functions API, adds the "bc_debug" parameter,
which will enable advanced debugging mode, adds a service step-script
"debug", which is executed before starting other steps-scripts in the
advanced debugging mode, which allows to monitor the data coming to
the <IN> of the next step. Also enables more verbose logging when the
daemon is running and ensures that the boot log is saved to the stage2.

Signed-off-by: Leonid Krivoshein <klark.devel@gmail.com>
---
 features/bootchain-core/README.md             | 31 ++++++-
 .../data/bin/bootchain-sh-functions           | 78 +++++++++++++++++-
 .../data/etc/initrd/cmdline.d/bootchain-core  |  1 +
 .../bootchain-core/data/lib/bootchain/debug   | 81 +++++++++++++++++++
 features/bootchain-core/data/sbin/chaind      | 73 ++++++++++++-----
 5 files changed, 242 insertions(+), 22 deletions(-)
 create mode 100755 features/bootchain-core/data/lib/bootchain/debug

diff --git a/features/bootchain-core/README.md b/features/bootchain-core/README.md
index 83897da..cea2d84 100644
--- a/features/bootchain-core/README.md
+++ b/features/bootchain-core/README.md
@@ -49,6 +49,8 @@ us to optimize fill in `initramfs` only which we are need.
 
 - Modularity: loading methods are initially separated from the common
   code and daemon.
+- `bootchain-sh-functions` extends the API of the original `pipeline-sh-functions`,
+  see the details in the corresponding section.
 - Via resolve_target() supports not only forward, but also reverse addressing,
   relative to the current step. For example, a record like `step-3/dir1/dev`
   will process the result of `dir1/dev`, made in the third step from the current
@@ -60,6 +62,11 @@ us to optimize fill in `initramfs` only which we are need.
 - The daemon can be configured when building initramfs via the included file
   configurations of `/etc/sysconfig/bootchain`, and not only through boot
   parameters, see the details in the corresponding section.
+- The `chaind` daemon offers visual and advanced debugging. By default, the log
+  is kept in `/var/log/chaind.log`.
+  Service step-script `debug` in advanced debugging mode is run before launching
+  any other step-script and allows you to visually track the received values at
+  each <IN>.
 
 Despite the differences, `chaind` is backward compatible with previously
 written steps for the `pipelined` daemon and does not require changes for
@@ -71,6 +78,10 @@ The configuration is defined in the file `/etc/sysconfig/bootchain` when
 building the initramfs image, is optional, and may contain the following
 parameters:
 
+- `BC_LOGFILE` - the full path to the log file or the name of a special device,
+  to which debugging messages will be output. In NATIVE mode, the default value
+  is `/var/log/chaind.log`, in COMPATIBILITY mode with `pipeline` the default
+  value is `/var/log/pipelined.log`.
 - `mntdir` - where to create subdirectories of the bootchain steps. In NATIVE
   mode the default value is `/dev/bootchain`, in COMPATIBILITY mode with
   `pipeline`, the default value is `/dev/pipeline`.
@@ -95,8 +106,10 @@ own needs.
 - `pipeline=name1[,name2][,name3]` - alias for `bootchain=...`.
 - `mountfs=target` - specifies the file or device to be mounted.
 - `overlayfs=list` - defines the list of elements to combine.
+- `bc_debug` - a boolean parameter that enables advanced debugging and forces
+  if the daemon completes successfully, copy boot log to the stage2.
 
-## bootchain-sh-functions API
+## bootchain-sh-functions extended API
 
 - check_parameter() - checks that the required parameter is not empty, otherwise
   it exits via fatal().
@@ -104,7 +117,21 @@ own needs.
   the index $callnum.
 - resolve_target() - output the path to a file, directory or device, depending
   on from the parameter.
-- run() - run an external command.
+- resolve_devname() - output the path to a special device file at the specified
+  directory. Usually the step directory contains a DEVNAME or dev file if the
+  device was the result of a step, then the function will return a readable
+  `/dev/node`.
+- debug() - text message output during extended debugging.
+- enter() - tracing during extended debugging: entering the specified function.
+- leave() - tracing during extended debugging: exit from the specified function.
+- run() - run an external command. With extended debugging, the executed command
+  will be logged.
+- fdump() - output of the contents of the specified file during extended
+  debugging.
+- assign() - assignment of the specified value to a variable that gets into
+  the log with advanced debugging. The left-hand expression is also computable.
+- initrd_version() - output of the current version of make-initrd. It is proposed
+  to move to make-initrd/data/bin/initrd-sh-functions after has_module().
 
 ## Examples
 
diff --git a/features/bootchain-core/data/bin/bootchain-sh-functions b/features/bootchain-core/data/bin/bootchain-sh-functions
index 8167e29..dcc1ab2 100644
--- a/features/bootchain-core/data/bin/bootchain-sh-functions
+++ b/features/bootchain-core/data/bin/bootchain-sh-functions
@@ -3,15 +3,22 @@
 if [ -z "${__bootchain_sh_functions-}" ]; then
 __bootchain_sh_functions=1
 
+BC_DEBUG=
+
 [ ! -s /etc/sysconfig/bootchain ] ||
 	. /etc/sysconfig/bootchain
 
+. initrd-sh-functions
 . /.initrd/initenv
 . shell-signal
 
+message_time=1
+
 if [ "${ROOT-}" = pipeline ]; then
+	BC_LOGFILE="${BC_LOGFILE:-/var/log/pipelined.log}"
 	mntdir="${mntdir:-/dev/pipeline}"
 else
+	BC_LOGFILE="${BC_LOGFILE:-/var/log/chaind.log}"
 	mntdir="${mntdir:-/dev/bootchain}"
 fi
 
@@ -81,10 +88,77 @@ resolve_target()
 	printf '%s' "$target"
 }
 
+resolve_devname()
+{
+	local dir="${1-}"
+	local devname=
+
+	[ -n "$dir" ] ||
+		dir="${prevdir-}"
+	[ -d "$dir" ] ||
+		return 0
+
+	if [ -s "$dir"/DEVNAME ]; then
+		read -r devname <"$dir"/DEVNAME ||:
+	elif [ -b "$dir"/dev ] || [ -c "$dir"/dev ]; then
+		devname="$(get_majmin "$dir"/dev ||:)"
+		devname="/sys/dev/block/$devname/uevent"
+		[ -b "$dir"/dev ] ||
+			devname="/sys/dev/char/$devname/uevent"
+		devname="/dev/$(sed -E -n 's/^DEVNAME=(.*)/\1/p' "$devname" ||:)"
+	fi
+
+	[ ! -b "$devname" ] && [ ! -c "$devname" ] ||
+		printf '%s' "$devname"
+}
+
+debug()
+{
+	[ -z "$BC_DEBUG" ] ||
+		message "[$callnum] $*"
+}
+
+enter()
+{
+	debug "ENTER: $*"
+}
+
+leave()
+{
+	debug "LEAVE: $*"
+}
+
 run()
 {
-	[ -z "${DEBUG-}" ] || message "[$callnum] RUN: $*"
-	"$@"
+	debug "RUN: $*"
+	"$@" || return $?
+}
+
+fdump()
+{
+	[ -n "$BC_DEBUG" ] && [ -f "$1" ] ||
+		return 0
+	{ printf '============================================================\n'
+	  cat -- "$1" ||:
+	  printf '============================================================\n\n'
+	} 1>&2
+}
+
+assign()
+{
+	local _v="" _k="$1" _e="${2-}"
+
+	eval "_v=\"${_e}\""
+	eval "${_k}=\"${_e}\""
+	debug "LET: ${_k}=\"${_v}\""
+}
+
+initrd_version()
+{
+	[ ! -s /etc/initrd-release ] ||
+		. /etc/initrd-release
+	local __version="${VERSION_ID-}"
+	printf '%s' "INITRAMFS${__version:+ $__version}"
 }
 
 fi # __bootchain_sh_functions
diff --git a/features/bootchain-core/data/etc/initrd/cmdline.d/bootchain-core b/features/bootchain-core/data/etc/initrd/cmdline.d/bootchain-core
index 1b1198c..4151a8d 100644
--- a/features/bootchain-core/data/etc/initrd/cmdline.d/bootchain-core
+++ b/features/bootchain-core/data/etc/initrd/cmdline.d/bootchain-core
@@ -1,4 +1,5 @@
 register_parameter string BOOTCHAIN
 register_alias BOOTCHAIN PIPELINE
+register_parameter bool BC_DEBUG
 register_array string MOUNTFS
 register_array string OVERLAYFS
diff --git a/features/bootchain-core/data/lib/bootchain/debug b/features/bootchain-core/data/lib/bootchain/debug
new file mode 100755
index 0000000..9ad4e96
--- /dev/null
+++ b/features/bootchain-core/data/lib/bootchain/debug
@@ -0,0 +1,81 @@
+#!/bin/bash -efu
+
+. bootchain-sh-functions
+
+
+listpvdir()
+{
+	# shellcheck disable=SC2012
+	if [ -z "${1-}" ]; then
+		ls -1F "$prevdir/" |sort |head -n20
+	else
+		ls -1F "$prevdir/" |sort |grep -svE "$1" |head -n20
+	fi
+}
+
+
+# Entry point
+message "$PROG for $name [$callnum] started"
+
+message "PREV DIR: $prevdir"
+message "Data DIR: $datadir"
+message "DEST DIR: $destdir"
+
+{ printf "##############################"
+
+  if [ -d "$prevdir" ]; then
+	printf "\nPrevious step results (%s):\n" "$prevdir"
+
+	if mountpoint -q -- "$prevdir"; then
+		listpvdir
+	elif [ ! -b "$prevdir/dev" ] &&
+		[ ! -c "$prevdir/dev" ] &&
+		[ ! -s "$prevdir/DEVNAME" ]
+	then
+		listpvdir
+	else
+		if [ -b "$prevdir/dev" ] || [ -c "$prevdir/dev" ]; then
+			devname="$(resolve_devname "$prevdir/dev")"
+			devno="$(get_majmin "$prevdir/dev" ||:)"
+			[ -z "$devno" ] || [ -z "$devname" ] ||
+				printf 'dev (%s -> %s)\n' "$devno" "$devname"
+		fi
+
+		if [ -s "$prevdir/DEVNAME" ]; then
+			read -r devname <"$prevdir/DEVNAME" 2>/dev/null ||
+				devname=
+			if [ -z "$devname" ]; then
+				printf 'DEVNAME\n'
+			else
+				devno="$(get_majmin "$devname")" ||
+					devno="ABSENT"
+				printf 'DEVNAME (%s -> %s)\n' "$devno" "$devname"
+			fi
+		fi
+
+		if [ -s "$prevdir/FILESIZE" ]; then
+			read -r fsize <"$prevdir/FILESIZE" 2>/dev/null ||
+				fsize="NOT READABLE"
+			printf 'FILESIZE (%s)\n' "$fsize"
+		fi
+
+		listpvdir "^(dev|DEVNAME|FILESIZE)$"
+	fi
+  fi
+
+  # FIXME: make this better to specify interested mount points only
+  [ -z "${OEM_CDROOT-}" ] && regex="$rootmnt" ||
+	regex="$rootmnt $OEM_CDROOT"
+  regex="$regex $mntdir"
+  regex="${regex//\//\\/}"
+  regex=" (${regex// /\|})\/"
+
+  if mount |grep -qsE "$regex"; then
+	printf "\nMount points and devices:\n"
+	mount |grep -sE "$regex"
+  fi
+
+  printf "##############################\n"
+} 1>&2
+
+message "$PROG for $name [$callnum] finished"
diff --git a/features/bootchain-core/data/sbin/chaind b/features/bootchain-core/data/sbin/chaind
index 08e5e58..ec4458e 100755
--- a/features/bootchain-core/data/sbin/chaind
+++ b/features/bootchain-core/data/sbin/chaind
@@ -1,11 +1,8 @@
 #!/bin/bash -efu
 
-. shell-error
-. shell-signal
+. bootchain-sh-functions
 
-message_time=1
 pidfile="/var/run/$PROG.pid"
-logfile="/var/log/$PROG.log"
 
 
 exit_handler()
@@ -16,26 +13,31 @@ exit_handler()
 	exit $rc
 }
 
+debug()
+{
+	[ -z "$BC_DEBUG" ] ||
+		message "$*"
+}
+
 
 [ ! -f "$pidfile" ] ||
 	fatal "already running"
-
 set_cleanup_handler exit_handler
 echo "$$" >"$pidfile"
 
-. bootchain-sh-functions
-
-
 [ "${RDLOG-}" != 'console' ] ||
-	logfile=/dev/console
+	BC_LOGFILE=/dev/console
+
+exec >"$BC_LOGFILE" 2>&1
 
-exec >"$logfile" 2>&1
-message "Starting server ..."
+message "Starting server [$(initrd_version)]..."
+debug "Booting with /proc/cmdline:"
+fdump /proc/cmdline
 
-mkdir -p -- "$mntdir"
+run mkdir -p -- "$mntdir"
 
-mountpoint -q "$mntdir" ||
-	mount -t tmpfs tmpfs "$mntdir" ||:
+mountpoint -q -- "$mntdir" ||
+	run mount -t tmpfs tmpfs "$mntdir" ||:
 
 stepnum=0
 chainsteps="$BOOTCHAIN"
@@ -47,23 +49,25 @@ while [ -n "$chainsteps" ]; do
 	exe="$handlerdir/$name"
 
 	if [ -x "$exe" ]; then
-		eval "callnum=\"\${callnum_$name:-0}\""
-
+		assign "callnum" "\${callnum_$name:-0}"
 		datadir="$mntdir/src/step$stepnum"
 		destdir="$mntdir/dst/step$stepnum"
 
 		[ "$stepnum" != 0 ] ||
 			prevdir=""
 
-		mkdir -p -- "$datadir" "$destdir"
+		run mkdir -p -- "$datadir" "$destdir"
 
 		if ! mountpoint -q "$destdir"; then
 			message "[$callnum] Handler: $exe"
 
 			export name callnum datadir destdir prevdir
 
+				[ -z "$BC_DEBUG" ] ||
+					run "$handlerdir/debug" ||:
 				rc=0
-				"$exe" || rc=$?
+				run "$exe" ||
+					rc=$?
 
 			if [ "$rc" != 0 ]; then
 				[ "$rc" != 2 ] ||
@@ -87,3 +91,36 @@ while [ -n "$chainsteps" ]; do
 
 	stepnum=$(($stepnum + 1))
 done
+
+[ -z "$chainsteps" ] ||
+	message "remaining steps after breaking loop: $chainsteps"
+
+if [ -z "$BC_DEBUG" ]; then
+	grep -qs " $mntdir/" /proc/mounts ||
+		run umount -- "$mntdir" &&
+		run rm -rf -- "$mntdir" ||:
+else
+	prevdir="$(readlink-e "$destdir" 2>/dev/null ||:)"
+	[ "$prevdir" = "$rootmnt" ] && datadir="" ||
+		datadir="$rootmnt"
+	destdir=
+	callnum=0
+	name=STAGE2
+
+	message "[$callnum] Handler: $handlerdir/debug"
+
+	export name callnum datadir destdir prevdir
+
+	run "$handlerdir/debug" ||:
+	debug "last step finished with exit code $rc"
+fi
+
+if [ -f "$BC_LOGFILE" ] && [ -n "$BC_DEBUG" ]; then
+	if [ -d "$rootmnt/var/log" ]; then
+		destdir="$rootmnt/var/log"
+	else
+		run mkdir -p -- "$mntdir"
+		destdir="$mntdir"
+	fi
+	run cp -Lf -- "$BC_LOGFILE" "$destdir/"
+fi
-- 
2.24.1