selftests/livepatch: Don't clear dmesg when running tests

Inspired by commit f131d9edc29d ("selftests/lkdtm: Don't clear dmesg
when running tests"), keep a reference dmesg copy when beginning each
test. This way check_result() can compare against the initial copy
rather than relying upon an empty log.

Signed-off-by: Joe Lawrence <[e-mail]>
Reviewed-by: Kamalesh Babulal <[e-mail]>
Reviewed-by: Yannick Cote <[e-mail]>
Reviewed-by: Petr Mladek <[e-mail]>
Acked-by: Miroslav Benes <[e-mail]>
Signed-off-by: Petr Mladek <[e-mail]>
Link: https://lore.kernel.org/r/[e-mail]

tools/testing/selftests/livepatch/README

···
 
 The test suite loads and unloads several test kernel modules to verify
 livepatch behavior.  Debug information is logged to the kernel's message
-buffer and parsed for expected messages.  (Note: the tests will clear
-the message buffer between individual tests.)
+buffer and parsed for expected messages.  (Note: the tests will compare
+the message buffer for only the duration of each individual test.)
 
 
 Config
···
 ------------
 
 See the common functions.sh file for the existing collection of utility
-functions, most importantly setup_config() and check_result().  The
-latter function greps the kernel's ring buffer for "livepatch:" and
-"test_klp" strings, so tests be sure to include one of those strings for
-result comparison.  Other utility functions include general module
-loading and livepatch loading helpers (waiting for patch transitions,
-sysfs entries, etc.)
+functions, most importantly setup_config(), start_test() and
+check_result().  The latter function greps the kernel's ring buffer for
+"livepatch:" and "test_klp" strings, so tests be sure to include one of
+those strings for result comparison.  Other utility functions include
+general module loading and livepatch loading helpers (waiting for patch
+transitions, sysfs entries, etc.)

tools/testing/selftests/livepatch/functions.sh

···
 	exit 1
 }
 
+# save existing dmesg so we can detect new content
+function save_dmesg() {
+	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
+	dmesg > "$SAVED_DMESG"
+}
+
+# cleanup temporary dmesg file from save_dmesg()
+function cleanup_dmesg_file() {
+	rm -f "$SAVED_DMESG"
+}
+
 function push_config() {
 	DYNAMIC_DEBUG=$(grep '^kernel/livepatch' /sys/kernel/debug/dynamic_debug/control | \
 			awk -F'[: ]' '{print "file " $1 " line " $2 " " $4}')
···
 	echo "livepatch: $result" > /dev/kmsg
 }
 
+function cleanup() {
+	pop_config
+	cleanup_dmesg_file
+}
+
 # setup_config - save the current config and set a script exit trap that
 #		 restores the original config.  Setup the dynamic debug
 #		 for verbose livepatching output and turn on
···
 	push_config
 	set_dynamic_debug
 	set_ftrace_enabled 1
-	trap pop_config EXIT INT TERM HUP
+	trap cleanup EXIT INT TERM HUP
 }
 
 # loop_until(cmd) - loop a command until it is successful or $MAX_RETRIES,
···
 		die "failed to set pre_patch_ret parameter for $mod module"
 }
 
+function start_test {
+	local test="$1"
+
+	save_dmesg
+	echo -n "TEST: $test ... "
+}
+
 # check_result() - verify dmesg output
 #	TODO - better filter, out of order msgs, etc?
 function check_result {
 	local expect="$*"
 	local result
 
-	result=$(dmesg | grep -v 'tainting' | grep -e 'livepatch:' -e 'test_klp' | sed 's/^\[[ 0-9.]*\] //')
+	# Note: when comparing dmesg output, the kernel log timestamps
+	# help differentiate repeated testing runs.  Remove them with a
+	# post-comparison sed filter.
+
+	result=$(dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
+		 grep -v 'tainting' | grep -e 'livepatch:' -e 'test_klp' | \
+		 sed 's/^\[[ 0-9.]*\] //')
 
 	if [[ "$expect" == "$result" ]] ; then
 		echo "ok"
···
 		echo -e "not ok\n\n$(diff -upr --label expected --label result <(echo "$expect") <(echo "$result"))\n"
 		die "livepatch kselftest(s) failed"
 	fi
+
+	cleanup_dmesg_file
 }

tools/testing/selftests/livepatch/test-callbacks.sh

···
 setup_config
 
 
-# TEST: target module before livepatch
-#
 # Test a combination of loading a kernel module and a livepatch that
 # patches a function in the first module.  Load the target module
 # before the livepatch module.  Unload them in the same order.
···
 #   unpatching transition starts.  klp_objects are reverted, post-patch
 #   callbacks execute and the transition completes.
 
-echo -n "TEST: target module before livepatch ... "
-dmesg -C
+start_test "target module before livepatch"
 
 load_mod $MOD_TARGET
 load_lp $MOD_LIVEPATCH
···
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_coming notifier
-#
 # This test is similar to the previous test, but (un)load the livepatch
 # module before the target kernel module.  This tests the livepatch
 # core's module_coming handler.
···
 # - On livepatch disable, all currently loaded klp_objects' (vmlinux and
 #   $MOD_TARGET) pre/post-unpatch callbacks are executed.
 
-echo -n "TEST: module_coming notifier ... "
-dmesg -C
+start_test "module_coming notifier"
 
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
···
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_going notifier
-#
 # Test loading the livepatch after a targeted kernel module, then unload
 # the kernel module before disabling the livepatch.  This tests the
 # livepatch core's module_going handler.
···
 # - When the livepatch is disabled, pre and post-unpatch callbacks are
 #   run for the remaining klp_object, vmlinux.
 
-echo -n "TEST: module_going notifier ... "
-dmesg -C
+start_test "module_going notifier"
 
 load_mod $MOD_TARGET
 load_lp $MOD_LIVEPATCH
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: module_coming and module_going notifiers
-#
 # This test is similar to the previous test, however the livepatch is
 # loaded first.  This tests the livepatch core's module_coming and
 # module_going handlers.
···
 #   from the $MOD_TARGET klp_object.  As such, only pre and
 #   post-unpatch callbacks are executed when this occurs.
 
-echo -n "TEST: module_coming and module_going notifiers ... "
-dmesg -C
+start_test "module_coming and module_going notifiers"
 
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: target module not present
-#
 # A simple test of loading a livepatch without one of its patch target
 # klp_objects ever loaded ($MOD_TARGET).
 #
···
 # - As expected, only pre/post-(un)patch handlers are executed for
 #   vmlinux.
 
-echo -n "TEST: target module not present ... "
-dmesg -C
+start_test "target module not present"
 
 load_lp $MOD_LIVEPATCH
 disable_lp $MOD_LIVEPATCH
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: pre-patch callback -ENODEV
-#
 # Test a scenario where a vmlinux pre-patch callback returns a non-zero
 # status (ie, failure).
 #
···
 #   The result is that the insmod command refuses to load the livepatch
 #   module.
 
-echo -n "TEST: pre-patch callback -ENODEV ... "
-dmesg -C
+start_test "pre-patch callback -ENODEV"
 
 load_mod $MOD_TARGET
 load_failing_mod $MOD_LIVEPATCH pre_patch_ret=-19
···
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_coming + pre-patch callback -ENODEV
-#
 # Similar to the previous test, setup a livepatch such that its vmlinux
 # pre-patch callback returns success.  However, when a targeted kernel
 # module is later loaded, have the livepatch return a failing status
···
 #
 # - Pre/post-unpatch callbacks are run for the vmlinux klp_object.
 
-echo -n "TEST: module_coming + pre-patch callback -ENODEV ... "
-dmesg -C
+start_test "module_coming + pre-patch callback -ENODEV"
 
 load_lp $MOD_LIVEPATCH
 set_pre_patch_ret $MOD_LIVEPATCH -19
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: multiple target modules
-#
 # Test loading multiple targeted kernel modules.  This test-case is
 # mainly for comparing with the next test-case.
 #
···
 #   module.  Post-patch callbacks are executed and the transition
 #   completes quickly.
 
-echo -n "TEST: multiple target modules ... "
-dmesg -C
+start_test "multiple target modules"
 
 load_mod $MOD_TARGET_BUSY block_transition=N
 load_lp $MOD_LIVEPATCH
···
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 
 
-# TEST: busy target module
-#
 # A similar test as the previous one, but force the "busy" kernel module
 # to block the livepatch transition.
 #
···
 #   klp_object's post-patch callbacks executed, the remaining
 #   klp_object's pre-unpatch callbacks are skipped.
 
-echo -n "TEST: busy target module ... "
-dmesg -C
+start_test "busy target module"
 
 load_mod $MOD_TARGET_BUSY block_transition=Y
 load_lp_nowait $MOD_LIVEPATCH
···
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 
 
-# TEST: multiple livepatches
-#
 # Test loading multiple livepatches.  This test-case is mainly for comparing
 # with the next test-case.
 #
···
 #   execute as each patch progresses through its (un)patching
 #   transition.
 
-echo -n "TEST: multiple livepatches ... "
-dmesg -C
+start_test "multiple livepatches"
 
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: atomic replace
-#
 # Load multiple livepatches, but the second as an 'atomic-replace'
 # patch.  When the latter loads, the original livepatch should be
 # disabled and *none* of its pre/post-unpatch callbacks executed.  On
···
 # - Once the atomic replace module is loaded, only its pre and post
 #   unpatch callbacks are executed.
 
-echo -n "TEST: atomic replace ... "
-dmesg -C
+start_test "atomic replace"
 
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2 replace=1

tools/testing/selftests/livepatch/test-ftrace.sh

···
 setup_config
 
 
-# TEST: livepatch interaction with ftrace_enabled sysctl
 # - turn ftrace_enabled OFF and verify livepatches can't load
 # - turn ftrace_enabled ON and verify livepatch can load
 # - verify that ftrace_enabled can't be turned OFF while a livepatch is loaded
 
-echo -n "TEST: livepatch interaction with ftrace_enabled sysctl ... "
-dmesg -C
+start_test "livepatch interaction with ftrace_enabled sysctl"
 
 set_ftrace_enabled 0
 load_failing_mod $MOD_LIVEPATCH

tools/testing/selftests/livepatch/test-livepatch.sh

···
 setup_config
 
 
-# TEST: basic function patching
 # - load a livepatch that modifies the output from /proc/cmdline and
 #   verify correct behavior
 # - unload the livepatch and make sure the patch was removed
 
-echo -n "TEST: basic function patching ... "
-dmesg -C
+start_test "basic function patching"
 
 load_lp $MOD_LIVEPATCH
 
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: multiple livepatches
 # - load a livepatch that modifies the output from /proc/cmdline and
 #   verify correct behavior
 # - load another livepatch and verify that both livepatches are active
 # - unload the second livepatch and verify that the first is still active
 # - unload the first livepatch and verify none are active
 
-echo -n "TEST: multiple livepatches ... "
-dmesg -C
+start_test "multiple livepatches"
 
 load_lp $MOD_LIVEPATCH
 
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: atomic replace livepatch
 # - load a livepatch that modifies the output from /proc/cmdline and
 #   verify correct behavior
 # - load an atomic replace livepatch and verify that only the second is active
···
 #   is still active
 # - remove the atomic replace livepatch and verify that none are active
 
-echo -n "TEST: atomic replace livepatch ... "
-dmesg -C
+start_test "atomic replace livepatch"
 
 load_lp $MOD_LIVEPATCH
 

tools/testing/selftests/livepatch/test-shadow-vars.sh

···
 setup_config
 
 
-# TEST: basic shadow variable API
 # - load a module that exercises the shadow variable API
 
-echo -n "TEST: basic shadow variable API ... "
-dmesg -C
+start_test "basic shadow variable API"
 
 load_mod $MOD_TEST
 unload_mod $MOD_TEST

tools/testing/selftests/livepatch/test-state.sh

···
 
 setup_config
 
-# TEST: Loading and removing a module that modifies the system state
 
-echo -n "TEST: system state modification ... "
-dmesg -C
+# Load and remove a module that modifies the system state
+
+start_test "system state modification"
 
 load_lp $MOD_LIVEPATCH
 disable_lp $MOD_LIVEPATCH
···
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: Take over system state change by a cumulative patch
+# Take over system state change by a cumulative patch
 
-echo -n "TEST: taking over system state modification ... "
-dmesg -C
+start_test "taking over system state modification"
 
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2
···
 % rmmod $MOD_LIVEPATCH2"
 
 
-# TEST: Take over system state change by a cumulative patch
+# Take over system state change by a cumulative patch
 
-echo -n "TEST: compatible cumulative livepatches ... "
-dmesg -C
+start_test "compatible cumulative livepatches"
 
 load_lp $MOD_LIVEPATCH2
 load_lp $MOD_LIVEPATCH3
···
 % rmmod $MOD_LIVEPATCH3"
 
 
-# TEST: Failure caused by incompatible cumulative livepatches
+# Failure caused by incompatible cumulative livepatches
 
-echo -n "TEST: incompatible cumulative livepatches ... "
-dmesg -C
+start_test "incompatible cumulative livepatches"
 
 load_lp $MOD_LIVEPATCH2
 load_failing_mod $MOD_LIVEPATCH