selftests/livepatch: simplify test-klp-callbacks busy target tests

The test-klp-callbacks script includes a few tests which rely on kernel
task timings that may not always execute as expected under system load.
These may generate out of sequence kernel log messages that result in
test failure.

Instead of using sleep timing windows to orchestrate these tests, add a
block_transition module parameter to communicate the test purpose and
utilize flush_queue() to serialize the test module's task output.

Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
Reviewed-by: Petr Mladek <pmladek@suse.com>
Acked-by: Miroslav Benes <mbenes@suse.cz>
Signed-off-by: Petr Mladek <pmladek@suse.com>
Link: https://lore.kernel.org/r/20200603182058.109470-2-ycote@redhat.com

Author: joe-lawrence

lib/livepatch/test_klp_callbacks_busy.c

@@ -5,34 +5,53 @@
 
 #include <linux/module.h>
 #include <linux/kernel.h>
+#include <linux/sched.h>
 #include <linux/workqueue.h>
 #include <linux/delay.h>
 
-static int sleep_secs;
-module_param(sleep_secs, int, 0644);
-MODULE_PARM_DESC(sleep_secs, "sleep_secs (default=0)");
+/* load/run-time control from sysfs writer  */
+static bool block_transition;
+module_param(block_transition, bool, 0644);
+MODULE_PARM_DESC(block_transition, "block_transition (default=false)");
 
 static void busymod_work_func(struct work_struct *work);
-static DECLARE_DELAYED_WORK(work, busymod_work_func);
+static DECLARE_WORK(work, busymod_work_func);
 
 static void busymod_work_func(struct work_struct *work)
 {
-	pr_info("%s, sleeping %d seconds ...\n", __func__, sleep_secs);
-	msleep(sleep_secs * 1000);
+	pr_info("%s enter\n", __func__);
+
+	while (READ_ONCE(block_transition)) {
+		/*
+		 * Busy-wait until the sysfs writer has acknowledged a
+		 * blocked transition and clears the flag.
+		 */
+		msleep(20);
+	}
+
 	pr_info("%s exit\n", __func__);
 }
 
 static int test_klp_callbacks_busy_init(void)
 {
 	pr_info("%s\n", __func__);
-	schedule_delayed_work(&work,
-		msecs_to_jiffies(1000 * 0));
+	schedule_work(&work);
+
+	if (!block_transition) {
+		/*
+		 * Serialize output: print all messages from the work
+		 * function before returning from init().
+		 */
+		flush_work(&work);
+	}
+
 	return 0;
 }
 
 static void test_klp_callbacks_busy_exit(void)
 {
-	cancel_delayed_work_sync(&work);
+	WRITE_ONCE(block_transition, false);
+	flush_work(&work);
 	pr_info("%s\n", __func__);
 }
 

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

@@ -356,19 +356,17 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 echo -n "TEST: multiple target modules ... "
 dmesg -C
 
-load_mod $MOD_TARGET_BUSY sleep_secs=0
-# give $MOD_TARGET_BUSY::busymod_work_func() a chance to run
-sleep 5
+load_mod $MOD_TARGET_BUSY block_transition=N
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
 unload_mod $MOD_TARGET
 disable_lp $MOD_LIVEPATCH
 unload_lp $MOD_LIVEPATCH
 unload_mod $MOD_TARGET_BUSY
 
-check_result "% modprobe $MOD_TARGET_BUSY sleep_secs=0
+check_result "% modprobe $MOD_TARGET_BUSY block_transition=N
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_init
-$MOD_TARGET_BUSY: busymod_work_func, sleeping 0 seconds ...
+$MOD_TARGET_BUSY: busymod_work_func enter
 $MOD_TARGET_BUSY: busymod_work_func exit
 % modprobe $MOD_LIVEPATCH
 livepatch: enabling patch '$MOD_LIVEPATCH'
@@ -404,11 +402,10 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 $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 do longer work.
+# to block the livepatch transition.
 #
 # The livepatching core will refuse to patch a task that is currently
 # executing a to-be-patched function -- the consistency model stalls the
@@ -417,8 +414,7 @@ $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 # function for a long time.  Meanwhile, load and unload other target
 # kernel modules while the livepatch transition is in progress.
 #
-# - Load the "busy" kernel module, this time make it do 10 seconds worth
-#   of work.
+# - Load the "busy" kernel module, this time make its work function loop
 #
 # - Meanwhile, the livepatch is loaded.  Notice that the patch
 #   transition does not complete as the targeted "busy" module is
@@ -438,20 +434,23 @@ $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 echo -n "TEST: busy target module ... "
 dmesg -C
 
-load_mod $MOD_TARGET_BUSY sleep_secs=10
+load_mod $MOD_TARGET_BUSY block_transition=Y
 load_lp_nowait $MOD_LIVEPATCH
-# Don't wait for transition, load $MOD_TARGET while the transition
-# is still stalled in $MOD_TARGET_BUSY::busymod_work_func()
-sleep 5
+
+# Wait until the livepatch reports in-transition state, i.e. that it's
+# stalled on $MOD_TARGET_BUSY::busymod_work_func()
+loop_until 'grep -q '^1$' /sys/kernel/livepatch/$MOD_LIVEPATCH/transition' ||
+	die "failed to stall transition"
+
 load_mod $MOD_TARGET
 unload_mod $MOD_TARGET
 disable_lp $MOD_LIVEPATCH
 unload_lp $MOD_LIVEPATCH
 unload_mod $MOD_TARGET_BUSY
 
-check_result "% modprobe $MOD_TARGET_BUSY sleep_secs=10
+check_result "% modprobe $MOD_TARGET_BUSY block_transition=Y
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_init
-$MOD_TARGET_BUSY: busymod_work_func, sleeping 10 seconds ...
+$MOD_TARGET_BUSY: busymod_work_func enter
 % modprobe $MOD_LIVEPATCH
 livepatch: enabling patch '$MOD_LIVEPATCH'
 livepatch: '$MOD_LIVEPATCH': initializing patching transition