postmarketos-initramfs: log to kernel ringbuffer (MR 5000)

Rework logging to always log the initramfs output to the kernel
ringbuffer and deprecate PMOS_NO_OUTPUT_REDIRECT in favour of following
the kernel loglevel.

I know it seems silly to use syslogd for this, but it's necessary to
buffer writes to /dev/kmsg per-line if we want to correctly set the log
level, and "tee" does not do this (it will write multiple lines at once,
resulting in "<14>" prints in the ringbuffer). The main advantage to
this is that we won't have kernel logs cut in half by initramfs logs
anymore, everything will be nicely line buffered!

The previous logging solution of multiple "tail" commands would actually
fail to log up to the last few lines before a crash due to how tail
works (it polls the file and buffers lines).

I attempted something like this before, but I stopped after running into
ratelimiting issues. These are now resolved by configuring the
printk_devkmsg sysctl.

Dropping PMOS_NO_OUTPUT_REDIRECT:

The general motivations behind PMOS_NO_OUTPUT_REDIRECT was to avoid
cluttering up the console with initramfs logs when they aren't wanted;
this is now handled instead by the kernels logging facility. We log to
the ringbuffer at LOGLEVEL_INFO, so if "quiet" is specified on the
cmdline (or the loglevel is otherwise set above info) then initramfs
logs will also not be shown.

Signed-off-by: Caleb Connolly <caleb@postmarketos.org>

main/postmarketos-initramfs/APKBUILD

@@ -90,8 +90,8 @@ sha512sums="
 9c0e8f6f61d5da191e03a1aa9d5d0ceb5baf1eae6dbb9bfb0af59817783525119ac8394b135f303f7b6434a3eab0b49185fb90379e06823db847a4999c75ce33  00-initramfs-base.dirs
 ab41b45b0613f25a61114ed8c8b92bc53c60838f6e2e0ba18c76e5369b2984e6023a0661887692673aca3f647f268c468a468f6b1ac424cfee609017a89481dd  00-initramfs-base.files
 8a4adad3785af474b36a09a05f6a3b2c4b4f43aac331a53b903abfa51ea12be1e3d1d807b7a6e66a1346815f3b0044daf8cd62e21e2dc75d2db13ee265a72985  00-initramfs-extra-base.files
-102cb49a5b44282afee7808945c69e9bb9310677efeefc681d92217f0399a90fcbb37eb9ac7aed89cc27c324780298c7c2de6de2bdb89a77499faad1c312e539  init.sh
+917a3e995c50d510d242413e76752b75cdd8e673a5e433481a3cbe883d917980cda50996a714d4be24b09ce19196184a487632dfa6d76d74d2cc3ec6513473aa  init.sh
-091cb54268a8b5a0f2793c64e3eb633d5f6aee084ab2b6fcdb39c56404c97e1256294d48cd991e39e067a5b4defc4c20a82005c74a470e97577cbe8339a5348d  init_functions.sh
+df53083f74b8824c3e537ddd84cb45a2470a129ba1060efac75661eb2fb86602a942ee4d34c9fb03a07e82a3c87cf37f16e690725e1f667a24c8920fe45042ee  init_functions.sh
 ba3275a9af788c7c782322a22a0f144d5e50e3498ea6886486a29331f23ae89cd32d500a3635cfa7cab369afba92edc18aeca64ccbf0cd589061cce23d15b46c  unudhcpd.conf
 675e7d5bee39b2df7d322117f8dcaccc274d61beaf4d50ead19bbf2109446d64b1c0aa0c5b4f9846eb6c1c403418f28f6364eff4537ba41120fbfcbc484b7da7  mdev.conf
 "

main/postmarketos-initramfs/init.sh

@@ -2,6 +2,7 @@
 # shellcheck disable=SC1091
 
 IN_CI="false"
+LOG_PREFIX="[pmOS-rd]"
 
 [ -e /hooks/10-verbose-initfs.sh ] && set -x
 
@@ -88,12 +89,19 @@ setup_bootchart2
 
 # Switch root
 run_hooks /hooks-cleanup
-killall mdev udevd 2>/dev/null
+
+# Restore stdout and stderr to their original values
+exec 1>&3 2>&4
+
+# Re-enable kmsg ratelimiting (might have been disabled for logging)
+echo ratelimit > /proc/sys/kernel/printk_devkmsg
+
+killall mdev udevd syslogd 2>/dev/null
 
 # shellcheck disable=SC2093
 exec switch_root /sysroot "$init"
 
-echo "ERROR: switch_root failed!"
+echo "$LOG_PREFIX ERROR: switch_root failed!" > /dev/kmsg
-echo "Looping forever. Install and use the debug-shell hook to debug this."
+echo "$LOG_PREFIX Looping forever. Install and use the debug-shell hook to debug this." > /dev/kmsg
-echo "For more information, see <https://postmarketos.org/debug-shell>"
+echo "$LOG_PREFIX For more information, see <https://postmarketos.org/debug-shell>" > /dev/kmsg
 fail_halt_boot

main/postmarketos-initramfs/init_functions.sh

@@ -7,30 +7,26 @@ PMOS_ROOT=""
 
 # Redirect stdout and stderr to logfile
 setup_log() {
-	local log_to_console=""
+	# Disable kmsg ratelimiting for userspace (it gets re-enabled again before switch_root)
+	echo on > /proc/sys/kernel/printk_devkmsg
 
-	grep -q PMOS_NO_OUTPUT_REDIRECT /proc/cmdline && log_to_console="true"
+	# Spawn syslogd to log to the kernel
+	syslogd -K
 
-	echo "### postmarketOS initramfs ###"
+	# Stash fd1/2 so we can restore them before switch_root
+	exec 3>&1 4>&2
 
-	if [ -z "$log_to_console" ]; then
+	local pmsg="/dev/pmsg0"
-		echo "Add PMOS_NO_OUTPUT_REDIRECT to your kernel command line"
+
-		echo "to enable initramfs logging to console (e.g. for serial)."
+	if ! [ -e "$pmsg" ]; then
+		pmsg="/dev/null"
 	fi
 
-	# Start redirect
+	# Redirect to a subshell which outputs to the logfile as well
-	exec >/pmOS_init.log 2>&1
+	# as to the kernel ringbuffer and pstore (if available).
-	echo "### postmarketOS initramfs ###"
+	# Process substitution is technically non-POSIX, but is supported by busybox
-
+	# shellcheck disable=SC3001
-	# Pipe logs to console if PMOS_NO_OUTPUT_REDIRECT is set
+	exec > >(tee /pmOS_init.log "$pmsg" | logger -t "$LOG_PREFIX" -p user.info) 2>&1
-	if [ -n "$log_to_console" ]; then
-		tail -f /pmOS_init.log > /dev/console &
-	fi
-
-	# Pipe logs to pmsg if PMOS_NO_OUTPUT_REDIRECT is set and /dev/pmsg0 is available
-	if [ -n "$log_to_console" ] && [ -e "/dev/pmsg0" ]; then
-		tail -f /pmOS_init.log > /dev/pmsg0 &
-	fi
 }
 
 mount_proc_sys_dev() {
@@ -46,6 +42,9 @@ mount_proc_sys_dev() {
 	# /dev/pts (needed for telnet)
 	mkdir -p /dev/pts
 	mount -t devpts devpts /dev/pts
+
+	# This is required for process substitution to work (as used in setup_log())
+	ln -s /proc/self/fd /dev/fd
 }
 
 setup_firmware_path() {