live-patching.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 0/3] selftests/livepatch: small script cleanups
@ 2020-06-10 17:20 Joe Lawrence
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
                   ` (2 more replies)
  0 siblings, 3 replies; 18+ messages in thread
From: Joe Lawrence @ 2020-06-10 17:20 UTC (permalink / raw)
  To: live-patching, linux-kselftest

This is a small collection of tweaks for the shellscript side of the
livepatch tests.  If anyone else has a small cleanup (or even just a
suggestion for a low-hanging change) and would like to tack it onto the
set, let me know.

based-on: livepatching.git, for-5.9/selftests-cleanup
merge-thru: livepatching.git

Joe Lawrence (3):
  selftests/livepatch: Don't clear dmesg when running tests
  selftests/livepatch: use $(dmesg --notime) instead of manually
    filtering
  selftests/livepatch: filter 'taints' from dmesg comparison

 tools/testing/selftests/livepatch/README      | 16 +++---
 .../testing/selftests/livepatch/functions.sh  | 16 +++++-
 .../selftests/livepatch/test-callbacks.sh     | 55 ++++---------------
 .../selftests/livepatch/test-ftrace.sh        |  5 +-
 .../selftests/livepatch/test-livepatch.sh     | 15 +----
 .../selftests/livepatch/test-shadow-vars.sh   |  5 +-
 .../testing/selftests/livepatch/test-state.sh | 20 ++-----
 7 files changed, 43 insertions(+), 89 deletions(-)

-- 
2.21.3


^ permalink raw reply	[flat|nested] 18+ messages in thread

* [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-10 17:20 [PATCH 0/3] selftests/livepatch: small script cleanups Joe Lawrence
@ 2020-06-10 17:20 ` Joe Lawrence
  2020-06-11  7:38   ` Miroslav Benes
                     ` (2 more replies)
  2020-06-10 17:21 ` [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering Joe Lawrence
  2020-06-10 17:21 ` [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison Joe Lawrence
  2 siblings, 3 replies; 18+ messages in thread
From: Joe Lawrence @ 2020-06-10 17:20 UTC (permalink / raw)
  To: live-patching, linux-kselftest

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 <joe.lawrence@redhat.com>
---
 tools/testing/selftests/livepatch/README      | 16 +++---
 .../testing/selftests/livepatch/functions.sh  | 16 +++++-
 .../selftests/livepatch/test-callbacks.sh     | 55 ++++---------------
 .../selftests/livepatch/test-ftrace.sh        |  5 +-
 .../selftests/livepatch/test-livepatch.sh     | 15 +----
 .../selftests/livepatch/test-shadow-vars.sh   |  5 +-
 .../testing/selftests/livepatch/test-state.sh | 20 ++-----
 7 files changed, 43 insertions(+), 89 deletions(-)

diff --git a/tools/testing/selftests/livepatch/README b/tools/testing/selftests/livepatch/README
index 621d325425c2..0942dd5826f8 100644
--- a/tools/testing/selftests/livepatch/README
+++ b/tools/testing/selftests/livepatch/README
@@ -6,8 +6,8 @@ This is a small set of sanity tests for the kernel livepatching.
 
 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
@@ -35,9 +35,9 @@ Adding tests
 ------------
 
 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.)
diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
index 2aab9791791d..e84375a33852 100644
--- a/tools/testing/selftests/livepatch/functions.sh
+++ b/tools/testing/selftests/livepatch/functions.sh
@@ -243,13 +243,25 @@ function set_pre_patch_ret {
 		die "failed to set pre_patch_ret parameter for $mod module"
 }
 
+function start_test {
+	local test="$1"
+
+	# Save existing dmesg so we can detect new content below
+	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
+	dmesg > "$SAVED_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.]*\] //')
+	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"
@@ -257,4 +269,6 @@ function check_result {
 		echo -e "not ok\n\n$(diff -upr --label expected --label result <(echo "$expect") <(echo "$result"))\n"
 		die "livepatch kselftest(s) failed"
 	fi
+
+	rm -f "$SAVED_DMESG"
 }
diff --git a/tools/testing/selftests/livepatch/test-callbacks.sh b/tools/testing/selftests/livepatch/test-callbacks.sh
index 32b57ba07f4f..c3d949da5bb7 100755
--- a/tools/testing/selftests/livepatch/test-callbacks.sh
+++ b/tools/testing/selftests/livepatch/test-callbacks.sh
@@ -12,7 +12,7 @@ MOD_TARGET_BUSY=test_klp_callbacks_busy
 setup_config
 
 
-# TEST: target module before livepatch
+start_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
@@ -28,9 +28,6 @@ setup_config
 #   unpatching transition starts.  klp_objects are reverted, post-patch
 #   callbacks execute and the transition completes.
 
-echo -n "TEST: target module before livepatch ... "
-dmesg -C
-
 load_mod $MOD_TARGET
 load_lp $MOD_LIVEPATCH
 disable_lp $MOD_LIVEPATCH
@@ -63,7 +60,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_coming notifier
+start_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
@@ -78,9 +75,6 @@ $MOD_TARGET: ${MOD_TARGET}_exit"
 # - 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
-
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
 disable_lp $MOD_LIVEPATCH
@@ -114,7 +108,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_going notifier
+start_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
@@ -129,9 +123,6 @@ $MOD_TARGET: ${MOD_TARGET}_exit"
 # - 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
-
 load_mod $MOD_TARGET
 load_lp $MOD_LIVEPATCH
 unload_mod $MOD_TARGET
@@ -165,7 +156,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: module_coming and module_going notifiers
+start_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
@@ -180,9 +171,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 #   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
-
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
 unload_mod $MOD_TARGET
@@ -217,7 +205,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: target module not present
+start_test "target module not present"
 #
 # A simple test of loading a livepatch without one of its patch target
 # klp_objects ever loaded ($MOD_TARGET).
@@ -227,9 +215,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 # - As expected, only pre/post-(un)patch handlers are executed for
 #   vmlinux.
 
-echo -n "TEST: target module not present ... "
-dmesg -C
-
 load_lp $MOD_LIVEPATCH
 disable_lp $MOD_LIVEPATCH
 unload_lp $MOD_LIVEPATCH
@@ -252,7 +237,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: pre-patch callback -ENODEV
+start_test "pre-patch callback -ENODEV"
 #
 # Test a scenario where a vmlinux pre-patch callback returns a non-zero
 # status (ie, failure).
@@ -265,9 +250,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 #   The result is that the insmod command refuses to load the livepatch
 #   module.
 
-echo -n "TEST: pre-patch callback -ENODEV ... "
-dmesg -C
-
 load_mod $MOD_TARGET
 load_failing_mod $MOD_LIVEPATCH pre_patch_ret=-19
 unload_mod $MOD_TARGET
@@ -288,7 +270,7 @@ modprobe: ERROR: could not insert '$MOD_LIVEPATCH': No such device
 $MOD_TARGET: ${MOD_TARGET}_exit"
 
 
-# TEST: module_coming + pre-patch callback -ENODEV
+start_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
@@ -307,9 +289,6 @@ $MOD_TARGET: ${MOD_TARGET}_exit"
 #
 # - Pre/post-unpatch callbacks are run for the vmlinux klp_object.
 
-echo -n "TEST: module_coming + pre-patch callback -ENODEV ... "
-dmesg -C
-
 load_lp $MOD_LIVEPATCH
 set_pre_patch_ret $MOD_LIVEPATCH -19
 load_failing_mod $MOD_TARGET
@@ -341,7 +320,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: multiple target modules
+start_test "multiple target modules"
 #
 # Test loading multiple targeted kernel modules.  This test-case is
 # mainly for comparing with the next test-case.
@@ -353,9 +332,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 #   module.  Post-patch callbacks are executed and the transition
 #   completes quickly.
 
-echo -n "TEST: multiple target modules ... "
-dmesg -C
-
 load_mod $MOD_TARGET_BUSY block_transition=N
 load_lp $MOD_LIVEPATCH
 load_mod $MOD_TARGET
@@ -402,7 +378,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 
 
-# TEST: busy target module
+start_test "busy target module"
 #
 # A similar test as the previous one, but force the "busy" kernel module
 # to block the livepatch transition.
@@ -431,9 +407,6 @@ $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 #   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
-
 load_mod $MOD_TARGET_BUSY block_transition=Y
 load_lp_nowait $MOD_LIVEPATCH
 
@@ -478,7 +451,7 @@ $MOD_TARGET_BUSY: busymod_work_func exit
 $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 
 
-# TEST: multiple livepatches
+start_test "multiple livepatches"
 #
 # Test loading multiple livepatches.  This test-case is mainly for comparing
 # with the next test-case.
@@ -487,9 +460,6 @@ $MOD_TARGET_BUSY: ${MOD_TARGET_BUSY}_exit"
 #   execute as each patch progresses through its (un)patching
 #   transition.
 
-echo -n "TEST: multiple livepatches ... "
-dmesg -C
-
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2
 disable_lp $MOD_LIVEPATCH2
@@ -531,7 +501,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: atomic replace
+start_test "atomic replace"
 #
 # Load multiple livepatches, but the second as an 'atomic-replace'
 # patch.  When the latter loads, the original livepatch should be
@@ -547,9 +517,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 # - Once the atomic replace module is loaded, only its pre and post
 #   unpatch callbacks are executed.
 
-echo -n "TEST: atomic replace ... "
-dmesg -C
-
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2 replace=1
 disable_lp $MOD_LIVEPATCH2
diff --git a/tools/testing/selftests/livepatch/test-ftrace.sh b/tools/testing/selftests/livepatch/test-ftrace.sh
index e2a76887f40a..c839f906ffc2 100755
--- a/tools/testing/selftests/livepatch/test-ftrace.sh
+++ b/tools/testing/selftests/livepatch/test-ftrace.sh
@@ -9,14 +9,11 @@ MOD_LIVEPATCH=test_klp_livepatch
 setup_config
 
 
-# TEST: livepatch interaction with ftrace_enabled sysctl
+start_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
-
 set_ftrace_enabled 0
 load_failing_mod $MOD_LIVEPATCH
 
diff --git a/tools/testing/selftests/livepatch/test-livepatch.sh b/tools/testing/selftests/livepatch/test-livepatch.sh
index 493e3df415a1..3b84ee34fe71 100755
--- a/tools/testing/selftests/livepatch/test-livepatch.sh
+++ b/tools/testing/selftests/livepatch/test-livepatch.sh
@@ -10,14 +10,11 @@ MOD_REPLACE=test_klp_atomic_replace
 setup_config
 
 
-# TEST: basic function patching
+start_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
-
 load_lp $MOD_LIVEPATCH
 
 if [[ "$(cat /proc/cmdline)" != "$MOD_LIVEPATCH: this has been live patched" ]] ; then
@@ -47,16 +44,13 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: multiple livepatches
+start_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
-
 load_lp $MOD_LIVEPATCH
 
 grep 'live patched' /proc/cmdline > /dev/kmsg
@@ -109,7 +103,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: atomic replace livepatch
+start_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
@@ -117,9 +111,6 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 #   is still active
 # - remove the atomic replace livepatch and verify that none are active
 
-echo -n "TEST: atomic replace livepatch ... "
-dmesg -C
-
 load_lp $MOD_LIVEPATCH
 
 grep 'live patched' /proc/cmdline > /dev/kmsg
diff --git a/tools/testing/selftests/livepatch/test-shadow-vars.sh b/tools/testing/selftests/livepatch/test-shadow-vars.sh
index 7c016548c2ea..71990d0b5d19 100755
--- a/tools/testing/selftests/livepatch/test-shadow-vars.sh
+++ b/tools/testing/selftests/livepatch/test-shadow-vars.sh
@@ -9,12 +9,9 @@ MOD_TEST=test_klp_shadow_vars
 setup_config
 
 
-# TEST: basic shadow variable API
+start_test "basic shadow variable API"
 # - load a module that exercises the shadow variable API
 
-echo -n "TEST: basic shadow variable API ... "
-dmesg -C
-
 load_mod $MOD_TEST
 unload_mod $MOD_TEST
 
diff --git a/tools/testing/selftests/livepatch/test-state.sh b/tools/testing/selftests/livepatch/test-state.sh
index a08212708115..bf8db1613961 100755
--- a/tools/testing/selftests/livepatch/test-state.sh
+++ b/tools/testing/selftests/livepatch/test-state.sh
@@ -10,10 +10,7 @@ MOD_LIVEPATCH3=test_klp_state3
 
 setup_config
 
-# TEST: Loading and removing a module that modifies the system state
-
-echo -n "TEST: system state modification ... "
-dmesg -C
+start_test "Loading and removing a module that modifies the system state"
 
 load_lp $MOD_LIVEPATCH
 disable_lp $MOD_LIVEPATCH
@@ -41,10 +38,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
 % rmmod $MOD_LIVEPATCH"
 
 
-# TEST: Take over system state change by a cumulative patch
-
-echo -n "TEST: taking over system state modification ... "
-dmesg -C
+start_test "Take over system state change by a cumulative patch"
 
 load_lp $MOD_LIVEPATCH
 load_lp $MOD_LIVEPATCH2
@@ -85,10 +79,7 @@ livepatch: '$MOD_LIVEPATCH2': unpatching complete
 % rmmod $MOD_LIVEPATCH2"
 
 
-# TEST: Take over system state change by a cumulative patch
-
-echo -n "TEST: compatible cumulative livepatches ... "
-dmesg -C
+start_test "Take over system state change by a cumulative patch"
 
 load_lp $MOD_LIVEPATCH2
 load_lp $MOD_LIVEPATCH3
@@ -142,10 +133,7 @@ livepatch: '$MOD_LIVEPATCH2': unpatching complete
 % rmmod $MOD_LIVEPATCH3"
 
 
-# TEST: Failure caused by incompatible cumulative livepatches
-
-echo -n "TEST: incompatible cumulative livepatches ... "
-dmesg -C
+start_test "Failure caused by incompatible cumulative livepatches"
 
 load_lp $MOD_LIVEPATCH2
 load_failing_mod $MOD_LIVEPATCH
-- 
2.21.3


^ permalink raw reply related	[flat|nested] 18+ messages in thread

* [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering
  2020-06-10 17:20 [PATCH 0/3] selftests/livepatch: small script cleanups Joe Lawrence
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
@ 2020-06-10 17:21 ` Joe Lawrence
  2020-06-12 10:12   ` Petr Mladek
  2020-06-10 17:21 ` [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison Joe Lawrence
  2 siblings, 1 reply; 18+ messages in thread
From: Joe Lawrence @ 2020-06-10 17:21 UTC (permalink / raw)
  To: live-patching, linux-kselftest

The dmesg utility already comes with a command line switch to omit
kernel timestamps, let's use it instead of applying an extra regex to
filter them out.

Now without the '[timestamp]: ' prefix at the beginning of the log
entry, revise the filtering regex to search for the 'livepatch:'
subsystem prefix at the beginning of the line.

Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
---
 tools/testing/selftests/livepatch/README       | 8 ++++----
 tools/testing/selftests/livepatch/functions.sh | 7 +++----
 2 files changed, 7 insertions(+), 8 deletions(-)

diff --git a/tools/testing/selftests/livepatch/README b/tools/testing/selftests/livepatch/README
index 0942dd5826f8..79dafab03017 100644
--- a/tools/testing/selftests/livepatch/README
+++ b/tools/testing/selftests/livepatch/README
@@ -37,7 +37,7 @@ Adding tests
 See the common functions.sh file for the existing collection of utility
 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.)
+the "^livepatch:" subsystem prefix and also any "test_klp" strings.
+Test log entries need include one of those for result comparison.  Other
+utility functions include general module loading and livepatch loading
+helpers (waiting for patch transitions, sysfs entries, etc.)
diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
index e84375a33852..83560c3df2ee 100644
--- a/tools/testing/selftests/livepatch/functions.sh
+++ b/tools/testing/selftests/livepatch/functions.sh
@@ -248,7 +248,7 @@ function start_test {
 
 	# Save existing dmesg so we can detect new content below
 	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
-	dmesg > "$SAVED_DMESG"
+	dmesg --notime > "$SAVED_DMESG"
 
 	echo -n "TEST: $test ... "
 }
@@ -259,9 +259,8 @@ function check_result {
 	local expect="$*"
 	local result
 
-	result=$(dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
-		 grep -v 'tainting' | grep -e 'livepatch:' -e 'test_klp' | \
-		 sed 's/^\[[ 0-9.]*\] //')
+	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
+		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
 
 	if [[ "$expect" == "$result" ]] ; then
 		echo "ok"
-- 
2.21.3


^ permalink raw reply related	[flat|nested] 18+ messages in thread

* [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-10 17:20 [PATCH 0/3] selftests/livepatch: small script cleanups Joe Lawrence
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
  2020-06-10 17:21 ` [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering Joe Lawrence
@ 2020-06-10 17:21 ` Joe Lawrence
  2020-06-11  7:39   ` Miroslav Benes
  2 siblings, 1 reply; 18+ messages in thread
From: Joe Lawrence @ 2020-06-10 17:21 UTC (permalink / raw)
  To: live-patching, linux-kselftest

The livepatch selftests currently filter out "tainting kernel with
TAINT_LIVEPATCH" messages which may be logged when loading livepatch
modules.

Further filter the log to drop "loading out-of-tree module taints
kernel" in the rare case the klp_test modules have been built
out-of-tree.

Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
---
 tools/testing/selftests/livepatch/functions.sh | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
index 83560c3df2ee..f5d4ef12f1cb 100644
--- a/tools/testing/selftests/livepatch/functions.sh
+++ b/tools/testing/selftests/livepatch/functions.sh
@@ -260,7 +260,8 @@ function check_result {
 	local result
 
 	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
-		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
+		 grep -e '^livepatch:' -e 'test_klp' | \
+		 grep -ve '\<taints\>' -ve '\<tainting\>')
 
 	if [[ "$expect" == "$result" ]] ; then
 		echo "ok"
-- 
2.21.3


^ permalink raw reply related	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
@ 2020-06-11  7:38   ` Miroslav Benes
  2020-06-11 13:01     ` Joe Lawrence
  2020-06-12  9:49   ` Petr Mladek
  2020-06-12 10:11   ` Petr Mladek
  2 siblings, 1 reply; 18+ messages in thread
From: Miroslav Benes @ 2020-06-11  7:38 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

Hi,

On Wed, 10 Jun 2020, Joe Lawrence wrote:

> diff --git a/tools/testing/selftests/livepatch/test-callbacks.sh b/tools/testing/selftests/livepatch/test-callbacks.sh
> index 32b57ba07f4f..c3d949da5bb7 100755
> --- a/tools/testing/selftests/livepatch/test-callbacks.sh
> +++ b/tools/testing/selftests/livepatch/test-callbacks.sh
> @@ -12,7 +12,7 @@ MOD_TARGET_BUSY=test_klp_callbacks_busy
>  setup_config
>  
>  
> -# TEST: target module before livepatch
> +start_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
> @@ -28,9 +28,6 @@ setup_config
>  #   unpatching transition starts.  klp_objects are reverted, post-patch
>  #   callbacks execute and the transition completes.
>  
> -echo -n "TEST: target module before livepatch ... "
> -dmesg -C
> -

A nit, but I think it would be better to place start_test here below the 
comment. The same for other occurrences in test-callbacks.sh.

[...]

> diff --git a/tools/testing/selftests/livepatch/test-state.sh b/tools/testing/selftests/livepatch/test-state.sh
> index a08212708115..bf8db1613961 100755
> --- a/tools/testing/selftests/livepatch/test-state.sh
> +++ b/tools/testing/selftests/livepatch/test-state.sh
> @@ -10,10 +10,7 @@ MOD_LIVEPATCH3=test_klp_state3
>  
>  setup_config
>  
> -# TEST: Loading and removing a module that modifies the system state
> -
> -echo -n "TEST: system state modification ... "
> -dmesg -C
> +start_test "Loading and removing a module that modifies the system state"

start_test should get the message from the original echo command and not 
the comment above, I think...

>  load_lp $MOD_LIVEPATCH
>  disable_lp $MOD_LIVEPATCH
> @@ -41,10 +38,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
>  % rmmod $MOD_LIVEPATCH"
>  
>  
> -# TEST: Take over system state change by a cumulative patch
> -
> -echo -n "TEST: taking over system state modification ... "
> -dmesg -C
> +start_test "Take over system state change by a cumulative patch"
>  
>  load_lp $MOD_LIVEPATCH
>  load_lp $MOD_LIVEPATCH2
> @@ -85,10 +79,7 @@ livepatch: '$MOD_LIVEPATCH2': unpatching complete
>  % rmmod $MOD_LIVEPATCH2"
>  
>  
> -# TEST: Take over system state change by a cumulative patch
> -
> -echo -n "TEST: compatible cumulative livepatches ... "
> -dmesg -C
> +start_test "Take over system state change by a cumulative patch"

...because now we have two "Take over system state change by a cumulative 
patch" tests in the log.

Miroslav

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-10 17:21 ` [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison Joe Lawrence
@ 2020-06-11  7:39   ` Miroslav Benes
  2020-06-11 13:10     ` Joe Lawrence
  0 siblings, 1 reply; 18+ messages in thread
From: Miroslav Benes @ 2020-06-11  7:39 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

On Wed, 10 Jun 2020, Joe Lawrence wrote:

> The livepatch selftests currently filter out "tainting kernel with
> TAINT_LIVEPATCH" messages which may be logged when loading livepatch
> modules.
> 
> Further filter the log to drop "loading out-of-tree module taints
> kernel" in the rare case the klp_test modules have been built
> out-of-tree.
> 
> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
> ---
>  tools/testing/selftests/livepatch/functions.sh | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
> index 83560c3df2ee..f5d4ef12f1cb 100644
> --- a/tools/testing/selftests/livepatch/functions.sh
> +++ b/tools/testing/selftests/livepatch/functions.sh
> @@ -260,7 +260,8 @@ function check_result {
>  	local result
>  
>  	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
> -		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
> +		 grep -e '^livepatch:' -e 'test_klp' | \
> +		 grep -ve '\<taints\>' -ve '\<tainting\>')

or make it just 'grep -v 'taint' ? It does not matter much though.

Miroslav

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-11  7:38   ` Miroslav Benes
@ 2020-06-11 13:01     ` Joe Lawrence
  2020-06-11 13:06       ` Miroslav Benes
  0 siblings, 1 reply; 18+ messages in thread
From: Joe Lawrence @ 2020-06-11 13:01 UTC (permalink / raw)
  To: Miroslav Benes; +Cc: live-patching, linux-kselftest

On 6/11/20 3:38 AM, Miroslav Benes wrote:
> Hi,
> 
> On Wed, 10 Jun 2020, Joe Lawrence wrote:
> 
>> diff --git a/tools/testing/selftests/livepatch/test-callbacks.sh b/tools/testing/selftests/livepatch/test-callbacks.sh
>> index 32b57ba07f4f..c3d949da5bb7 100755
>> --- a/tools/testing/selftests/livepatch/test-callbacks.sh
>> +++ b/tools/testing/selftests/livepatch/test-callbacks.sh
>> @@ -12,7 +12,7 @@ MOD_TARGET_BUSY=test_klp_callbacks_busy
>>   setup_config
>>   
>>   
>> -# TEST: target module before livepatch
>> +start_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
>> @@ -28,9 +28,6 @@ setup_config
>>   #   unpatching transition starts.  klp_objects are reverted, post-patch
>>   #   callbacks execute and the transition completes.
>>   
>> -echo -n "TEST: target module before livepatch ... "
>> -dmesg -C
>> -
> 
> A nit, but I think it would be better to place start_test here below the
> comment. The same for other occurrences in test-callbacks.sh.
> 

The idea was to remove the duplicate # TEST: comment and then the same 
echo -n "TEST: ..." entries.

Would it still look okay if we move start_test to below the comment and 
omit that # TEST ... part?  (This might be what you're suggesting, but I 
wanted to make sure.)

> [...]
> 
>> diff --git a/tools/testing/selftests/livepatch/test-state.sh b/tools/testing/selftests/livepatch/test-state.sh
>> index a08212708115..bf8db1613961 100755
>> --- a/tools/testing/selftests/livepatch/test-state.sh
>> +++ b/tools/testing/selftests/livepatch/test-state.sh
>> @@ -10,10 +10,7 @@ MOD_LIVEPATCH3=test_klp_state3
>>   
>>   setup_config
>>   
>> -# TEST: Loading and removing a module that modifies the system state
>> -
>> -echo -n "TEST: system state modification ... "
>> -dmesg -C
>> +start_test "Loading and removing a module that modifies the system state"
> 
> start_test should get the message from the original echo command and not
> the comment above, I think...
> 

Yup, good eye.

>>   load_lp $MOD_LIVEPATCH
>>   disable_lp $MOD_LIVEPATCH
>> @@ -41,10 +38,7 @@ livepatch: '$MOD_LIVEPATCH': unpatching complete
>>   % rmmod $MOD_LIVEPATCH"
>>   
>>   
>> -# TEST: Take over system state change by a cumulative patch
>> -
>> -echo -n "TEST: taking over system state modification ... "
>> -dmesg -C
>> +start_test "Take over system state change by a cumulative patch"
>>   
>>   load_lp $MOD_LIVEPATCH
>>   load_lp $MOD_LIVEPATCH2
>> @@ -85,10 +79,7 @@ livepatch: '$MOD_LIVEPATCH2': unpatching complete
>>   % rmmod $MOD_LIVEPATCH2"
>>   
>>   
>> -# TEST: Take over system state change by a cumulative patch
>> -
>> -echo -n "TEST: compatible cumulative livepatches ... "
>> -dmesg -C
>> +start_test "Take over system state change by a cumulative patch"
> 
> ...because now we have two "Take over system state change by a cumulative
> patch" tests in the log.
> 

Right, the start_test messages should be unique.  I'll fix those up for v2.

-- Joe


^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-11 13:01     ` Joe Lawrence
@ 2020-06-11 13:06       ` Miroslav Benes
  0 siblings, 0 replies; 18+ messages in thread
From: Miroslav Benes @ 2020-06-11 13:06 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

On Thu, 11 Jun 2020, Joe Lawrence wrote:

> On 6/11/20 3:38 AM, Miroslav Benes wrote:
> > Hi,
> > 
> > On Wed, 10 Jun 2020, Joe Lawrence wrote:
> > 
> >> diff --git a/tools/testing/selftests/livepatch/test-callbacks.sh
> >> b/tools/testing/selftests/livepatch/test-callbacks.sh
> >> index 32b57ba07f4f..c3d949da5bb7 100755
> >> --- a/tools/testing/selftests/livepatch/test-callbacks.sh
> >> +++ b/tools/testing/selftests/livepatch/test-callbacks.sh
> >> @@ -12,7 +12,7 @@ MOD_TARGET_BUSY=test_klp_callbacks_busy
> >>   setup_config
> >>   
> >>   
> >> -# TEST: target module before livepatch
> >> +start_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
> >> @@ -28,9 +28,6 @@ setup_config
> >>   #   unpatching transition starts.  klp_objects are reverted, post-patch
> >>   #   callbacks execute and the transition completes.
> >>   
> >> -echo -n "TEST: target module before livepatch ... "
> >> -dmesg -C
> >> -
> > 
> > A nit, but I think it would be better to place start_test here below the
> > comment. The same for other occurrences in test-callbacks.sh.
> > 
> 
> The idea was to remove the duplicate # TEST: comment and then the same echo -n
> "TEST: ..." entries.
> 
> Would it still look okay if we move start_test to below the comment and omit
> that # TEST ... part?  (This might be what you're suggesting, but I wanted to
> make sure.)

Yes, that is what I meant. I am sorry because it was not clear.

Thanks
Miroslav

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-11  7:39   ` Miroslav Benes
@ 2020-06-11 13:10     ` Joe Lawrence
  2020-06-12 11:47       ` Petr Mladek
  0 siblings, 1 reply; 18+ messages in thread
From: Joe Lawrence @ 2020-06-11 13:10 UTC (permalink / raw)
  To: Miroslav Benes; +Cc: live-patching, linux-kselftest

On 6/11/20 3:39 AM, Miroslav Benes wrote:
> On Wed, 10 Jun 2020, Joe Lawrence wrote:
> 
>> The livepatch selftests currently filter out "tainting kernel with
>> TAINT_LIVEPATCH" messages which may be logged when loading livepatch
>> modules.
>>
>> Further filter the log to drop "loading out-of-tree module taints
>> kernel" in the rare case the klp_test modules have been built
>> out-of-tree.
>>
>> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
>> ---
>>   tools/testing/selftests/livepatch/functions.sh | 3 ++-
>>   1 file changed, 2 insertions(+), 1 deletion(-)
>>
>> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
>> index 83560c3df2ee..f5d4ef12f1cb 100644
>> --- a/tools/testing/selftests/livepatch/functions.sh
>> +++ b/tools/testing/selftests/livepatch/functions.sh
>> @@ -260,7 +260,8 @@ function check_result {
>>   	local result
>>   
>>   	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
>> -		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
>> +		 grep -e '^livepatch:' -e 'test_klp' | \
>> +		 grep -ve '\<taints\>' -ve '\<tainting\>')
> 
> or make it just 'grep -v 'taint' ? It does not matter much though.
> 

I don't know of any larger words* that may hit a partial match on 
"taint", but I figured the two word bounded regexes would be more specific.


* https://www.wordfind.com/contains/taint/ : guess I need to up my 
scrabble game :D

-- Joe


^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
  2020-06-11  7:38   ` Miroslav Benes
@ 2020-06-12  9:49   ` Petr Mladek
  2020-06-14 15:19     ` Joe Lawrence
  2020-06-12 10:11   ` Petr Mladek
  2 siblings, 1 reply; 18+ messages in thread
From: Petr Mladek @ 2020-06-12  9:49 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

On Wed 2020-06-10 13:20:59, Joe Lawrence wrote:
> 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 <joe.lawrence@redhat.com>
> ---
>  tools/testing/selftests/livepatch/README      | 16 +++---
>  .../testing/selftests/livepatch/functions.sh  | 16 +++++-
>  .../selftests/livepatch/test-callbacks.sh     | 55 ++++---------------
>  .../selftests/livepatch/test-ftrace.sh        |  5 +-
>  .../selftests/livepatch/test-livepatch.sh     | 15 +----
>  .../selftests/livepatch/test-shadow-vars.sh   |  5 +-
>  .../testing/selftests/livepatch/test-state.sh | 20 ++-----
>  7 files changed, 43 insertions(+), 89 deletions(-)
> 
> diff --git a/tools/testing/selftests/livepatch/README b/tools/testing/selftests/livepatch/README
> index 621d325425c2..0942dd5826f8 100644
> --- a/tools/testing/selftests/livepatch/README
> +++ b/tools/testing/selftests/livepatch/README
> @@ -6,8 +6,8 @@ This is a small set of sanity tests for the kernel livepatching.
>  
>  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
> @@ -35,9 +35,9 @@ Adding tests
>  ------------
>  
>  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.)
> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
> index 2aab9791791d..e84375a33852 100644
> --- a/tools/testing/selftests/livepatch/functions.sh
> +++ b/tools/testing/selftests/livepatch/functions.sh
> @@ -243,13 +243,25 @@ function set_pre_patch_ret {
>  		die "failed to set pre_patch_ret parameter for $mod module"
>  }
>  
> +function start_test {
> +	local test="$1"
> +
> +	# Save existing dmesg so we can detect new content below
> +	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)

There is a nice trick how to remove the temporary files even
when the script fails from other reasons. The following should
do the job:

function cleanup {
	rm -f "$SAVED_DMESG"
}

trap cleanup EXIT

> +	dmesg > "$SAVED_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.]*\] //')
> +	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"
> @@ -257,4 +269,6 @@ function check_result {
>  		echo -e "not ok\n\n$(diff -upr --label expected --label result <(echo "$expect") <(echo "$result"))\n"
>  		die "livepatch kselftest(s) failed"
>  	fi
> +
> +	rm -f "$SAVED_DMESG"

This change will not be necessary with the above trap handler.

Otherwise, I really like the change. I was always a bit worried that these
tests were clearing all other messages.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
  2020-06-11  7:38   ` Miroslav Benes
  2020-06-12  9:49   ` Petr Mladek
@ 2020-06-12 10:11   ` Petr Mladek
  2 siblings, 0 replies; 18+ messages in thread
From: Petr Mladek @ 2020-06-12 10:11 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

On Wed 2020-06-10 13:20:59, Joe Lawrence wrote:
> 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 <joe.lawrence@redhat.com>
> ---
>  tools/testing/selftests/livepatch/README      | 16 +++---
>  .../testing/selftests/livepatch/functions.sh  | 16 +++++-
>  .../selftests/livepatch/test-callbacks.sh     | 55 ++++---------------
>  .../selftests/livepatch/test-ftrace.sh        |  5 +-
>  .../selftests/livepatch/test-livepatch.sh     | 15 +----
>  .../selftests/livepatch/test-shadow-vars.sh   |  5 +-
>  .../testing/selftests/livepatch/test-state.sh | 20 ++-----
>  7 files changed, 43 insertions(+), 89 deletions(-)
> 
> diff --git a/tools/testing/selftests/livepatch/README b/tools/testing/selftests/livepatch/README
> index 621d325425c2..0942dd5826f8 100644
> --- a/tools/testing/selftests/livepatch/README
> +++ b/tools/testing/selftests/livepatch/README
> @@ -6,8 +6,8 @@ This is a small set of sanity tests for the kernel livepatching.
>  
>  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
> @@ -35,9 +35,9 @@ Adding tests
>  ------------
>  
>  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.)
> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
> index 2aab9791791d..e84375a33852 100644
> --- a/tools/testing/selftests/livepatch/functions.sh
> +++ b/tools/testing/selftests/livepatch/functions.sh
> @@ -243,13 +243,25 @@ function set_pre_patch_ret {
>  		die "failed to set pre_patch_ret parameter for $mod module"
>  }
>  
> +function start_test {
> +	local test="$1"
> +
> +	# Save existing dmesg so we can detect new content below
> +	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
> +	dmesg > "$SAVED_DMESG"
> +

One more thing. Could we print a delimiter into dmesg log so that it
is easier to distinguish different tests.

The following looks fine to me but I do not resist on exactly
this format:

	log "===== TEST: $test ====="

> +	echo -n "TEST: $test ... "
> +}
> +

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering
  2020-06-10 17:21 ` [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering Joe Lawrence
@ 2020-06-12 10:12   ` Petr Mladek
  0 siblings, 0 replies; 18+ messages in thread
From: Petr Mladek @ 2020-06-12 10:12 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: live-patching, linux-kselftest

On Wed 2020-06-10 13:21:00, Joe Lawrence wrote:
> The dmesg utility already comes with a command line switch to omit
> kernel timestamps, let's use it instead of applying an extra regex to
> filter them out.
> 
> Now without the '[timestamp]: ' prefix at the beginning of the log
> entry, revise the filtering regex to search for the 'livepatch:'
> subsystem prefix at the beginning of the line.
> 
> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>

Nice simplification.

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-11 13:10     ` Joe Lawrence
@ 2020-06-12 11:47       ` Petr Mladek
  2020-06-12 12:57         ` Kamalesh Babulal
  0 siblings, 1 reply; 18+ messages in thread
From: Petr Mladek @ 2020-06-12 11:47 UTC (permalink / raw)
  To: Joe Lawrence; +Cc: Miroslav Benes, live-patching, linux-kselftest

On Thu 2020-06-11 09:10:38, Joe Lawrence wrote:
> On 6/11/20 3:39 AM, Miroslav Benes wrote:
> > On Wed, 10 Jun 2020, Joe Lawrence wrote:
> > 
> > > The livepatch selftests currently filter out "tainting kernel with
> > > TAINT_LIVEPATCH" messages which may be logged when loading livepatch
> > > modules.
> > > 
> > > Further filter the log to drop "loading out-of-tree module taints
> > > kernel" in the rare case the klp_test modules have been built
> > > out-of-tree.
> > > 
> > > Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
> > > ---
> > >   tools/testing/selftests/livepatch/functions.sh | 3 ++-
> > >   1 file changed, 2 insertions(+), 1 deletion(-)
> > > 
> > > diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
> > > index 83560c3df2ee..f5d4ef12f1cb 100644
> > > --- a/tools/testing/selftests/livepatch/functions.sh
> > > +++ b/tools/testing/selftests/livepatch/functions.sh
> > > @@ -260,7 +260,8 @@ function check_result {
> > >   	local result
> > >   	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
> > > -		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
> > > +		 grep -e '^livepatch:' -e 'test_klp' | \
> > > +		 grep -ve '\<taints\>' -ve '\<tainting\>')
> > 
> > or make it just 'grep -v 'taint' ? It does not matter much though.
> > 
> 
> I don't know of any larger words* that may hit a partial match on "taint",
> but I figured the two word bounded regexes would be more specific.

I do not have strong opinion. I am fine with both current and Mirek's proposal.

I am just curious where \< and \> regexp substitutions are documented.
I see the following at the very end of "man re_syntax":

   \< and \> are synonyms for  “[[:<:]]” and “[[:>:]]” respectively

But I am not able to find documentation for “[[:<:]]” and “[[:>:]].
Even google looks helpless ;-)

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-12 11:47       ` Petr Mladek
@ 2020-06-12 12:57         ` Kamalesh Babulal
  2020-06-14 14:45           ` Joe Lawrence
  0 siblings, 1 reply; 18+ messages in thread
From: Kamalesh Babulal @ 2020-06-12 12:57 UTC (permalink / raw)
  To: Petr Mladek; +Cc: Joe Lawrence, Miroslav Benes, live-patching, linux-kselftest

On 6/12/20 5:17 PM, Petr Mladek wrote:
> On Thu 2020-06-11 09:10:38, Joe Lawrence wrote:
>> On 6/11/20 3:39 AM, Miroslav Benes wrote:
>>> On Wed, 10 Jun 2020, Joe Lawrence wrote:
>>>
>>>> The livepatch selftests currently filter out "tainting kernel with
>>>> TAINT_LIVEPATCH" messages which may be logged when loading livepatch
>>>> modules.
>>>>
>>>> Further filter the log to drop "loading out-of-tree module taints
>>>> kernel" in the rare case the klp_test modules have been built
>>>> out-of-tree.
>>>>
>>>> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
>>>> ---
>>>>   tools/testing/selftests/livepatch/functions.sh | 3 ++-
>>>>   1 file changed, 2 insertions(+), 1 deletion(-)
>>>>
>>>> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
>>>> index 83560c3df2ee..f5d4ef12f1cb 100644
>>>> --- a/tools/testing/selftests/livepatch/functions.sh
>>>> +++ b/tools/testing/selftests/livepatch/functions.sh
>>>> @@ -260,7 +260,8 @@ function check_result {
>>>>   	local result
>>>>   	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
>>>> -		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
>>>> +		 grep -e '^livepatch:' -e 'test_klp' | \
>>>> +		 grep -ve '\<taints\>' -ve '\<tainting\>')
>>>
>>> or make it just 'grep -v 'taint' ? It does not matter much though.
>>>
>>
>> I don't know of any larger words* that may hit a partial match on "taint",
>> but I figured the two word bounded regexes would be more specific.
> 
> I do not have strong opinion. I am fine with both current and Mirek's proposal.
> 
> I am just curious where \< and \> regexp substitutions are documented.
> I see the following at the very end of "man re_syntax":
> 
>    \< and \> are synonyms for  “[[:<:]]” and “[[:>:]]” respectively
> 
> But I am not able to find documentation for “[[:<:]]” and “[[:>:]].
> Even google looks helpless ;-)
> 

AFAIK, using \< and \> matches exact word.  Whereas when used individually,
\< matches beginning and \> matches end of the word.

-- 
Kamalesh

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-12 12:57         ` Kamalesh Babulal
@ 2020-06-14 14:45           ` Joe Lawrence
  2020-06-15  7:55             ` Miroslav Benes
  0 siblings, 1 reply; 18+ messages in thread
From: Joe Lawrence @ 2020-06-14 14:45 UTC (permalink / raw)
  To: Kamalesh Babulal, Petr Mladek
  Cc: Miroslav Benes, live-patching, linux-kselftest

On 6/12/20 8:57 AM, Kamalesh Babulal wrote:
> On 6/12/20 5:17 PM, Petr Mladek wrote:
>> On Thu 2020-06-11 09:10:38, Joe Lawrence wrote:
>>> On 6/11/20 3:39 AM, Miroslav Benes wrote:
>>>> On Wed, 10 Jun 2020, Joe Lawrence wrote:
>>>>
>>>>> The livepatch selftests currently filter out "tainting kernel with
>>>>> TAINT_LIVEPATCH" messages which may be logged when loading livepatch
>>>>> modules.
>>>>>
>>>>> Further filter the log to drop "loading out-of-tree module taints
>>>>> kernel" in the rare case the klp_test modules have been built
>>>>> out-of-tree.
>>>>>
>>>>> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
>>>>> ---
>>>>>    tools/testing/selftests/livepatch/functions.sh | 3 ++-
>>>>>    1 file changed, 2 insertions(+), 1 deletion(-)
>>>>>
>>>>> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
>>>>> index 83560c3df2ee..f5d4ef12f1cb 100644
>>>>> --- a/tools/testing/selftests/livepatch/functions.sh
>>>>> +++ b/tools/testing/selftests/livepatch/functions.sh
>>>>> @@ -260,7 +260,8 @@ function check_result {
>>>>>    	local result
>>>>>    	result=$(dmesg --notime | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
>>>>> -		 grep -v 'tainting' | grep -e '^livepatch:' -e 'test_klp')
>>>>> +		 grep -e '^livepatch:' -e 'test_klp' | \
>>>>> +		 grep -ve '\<taints\>' -ve '\<tainting\>')
>>>>
>>>> or make it just 'grep -v 'taint' ? It does not matter much though.
>>>>
>>>
>>> I don't know of any larger words* that may hit a partial match on "taint",
>>> but I figured the two word bounded regexes would be more specific.
>>
>> I do not have strong opinion. I am fine with both current and Mirek's proposal.
>>
>> I am just curious where \< and \> regexp substitutions are documented.
>> I see the following at the very end of "man re_syntax":
>>
>>     \< and \> are synonyms for  “[[:<:]]� and “[[:>:]]� respectively
>>
>> But I am not able to find documentation for “[[:<:]]� and “[[:>:]].
>> Even google looks helpless ;-)
>>
> 
> AFAIK, using \< and \> matches exact word.  Whereas when used individually,
> \< matches beginning and \> matches end of the word.
> 

 From 
https://www.gnu.org/software/grep/manual/grep.html#The-Backslash-Character-and-Special-Expressions 
:

The ‘\’ character, when followed by certain ordinary characters, takes a 
special meaning:

...

‘\<’

     Match the empty string at the beginning of word.
‘\>’

     Match the empty string at the end of word.


I'd be happy to use any other (more readable!) whole-word matching grep 
trick, this \<one\> just happens to be committed to my cmdline muscle 
memory.

-- Joe


^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests
  2020-06-12  9:49   ` Petr Mladek
@ 2020-06-14 15:19     ` Joe Lawrence
  0 siblings, 0 replies; 18+ messages in thread
From: Joe Lawrence @ 2020-06-14 15:19 UTC (permalink / raw)
  To: Petr Mladek; +Cc: live-patching, linux-kselftest

On 6/12/20 5:49 AM, Petr Mladek wrote:
> On Wed 2020-06-10 13:20:59, Joe Lawrence wrote:
>> [ ... snip ... ]
>>   
>> +function start_test {
>> +	local test="$1"
>> +
>> +	# Save existing dmesg so we can detect new content below
>> +	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
> 
> There is a nice trick how to remove the temporary files even
> when the script fails from other reasons. The following should
> do the job:
> 
> function cleanup {
> 	rm -f "$SAVED_DMESG"
> }
> 
> trap cleanup EXIT
> 

Right, we currently trap EXIT INT TERM HUP to pop the dynamic debug and 
kernel.ftrace_enabled sysctl settings.  I can add a cleanup() function 
to take care of both the settings and the tmp file.

>> +	dmesg > "$SAVED_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.]*\] //')
>> +	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"
>> @@ -257,4 +269,6 @@ function check_result {
>>   		echo -e "not ok\n\n$(diff -upr --label expected --label result <(echo "$expect") <(echo "$result"))\n"
>>   		die "livepatch kselftest(s) failed"
>>   	fi
>> +
>> +	rm -f "$SAVED_DMESG"
> 
> This change will not be necessary with the above trap handler.

Well start_test() and check_result() are called multiple times per 
script.  That means that with the original v1 change, we're creating new 
$SAVED_DMESG files per start_test() since check_result() is comparing 
only the new entries from test to test.

So I think this particular hunk in the modification would be necessary 
even with the trap handler.  The trap handler would still be nice to 
have in case the script is interrupted though.

> 
> Otherwise, I really like the change. I was always a bit worried that these
> tests were clearing all other messages.
> 

Yup, we ran into an instance internally where another test was failing 
because were blowing away the logs :(


-- Joe


^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-14 14:45           ` Joe Lawrence
@ 2020-06-15  7:55             ` Miroslav Benes
  2020-06-15  9:19               ` Petr Mladek
  0 siblings, 1 reply; 18+ messages in thread
From: Miroslav Benes @ 2020-06-15  7:55 UTC (permalink / raw)
  To: Joe Lawrence
  Cc: Kamalesh Babulal, Petr Mladek, live-patching, linux-kselftest

[-- Attachment #1: Type: text/plain, Size: 568 bytes --]

> From
> https://www.gnu.org/software/grep/manual/grep.html#The-Backslash-Character-and-Special-Expressions
> :
> 
> The ‘\’ character, when followed by certain ordinary characters, takes a
> special meaning:
> 
> ...
> 
> ‘\<’
> 
>     Match the empty string at the beginning of word.
> ‘\>’
> 
>     Match the empty string at the end of word.
> 
> 
> I'd be happy to use any other (more readable!) whole-word matching grep trick,
> this \<one\> just happens to be committed to my cmdline muscle memory.

There is 'grep -w' which I use for this.

Miroslav

^ permalink raw reply	[flat|nested] 18+ messages in thread

* Re: [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison
  2020-06-15  7:55             ` Miroslav Benes
@ 2020-06-15  9:19               ` Petr Mladek
  0 siblings, 0 replies; 18+ messages in thread
From: Petr Mladek @ 2020-06-15  9:19 UTC (permalink / raw)
  To: Miroslav Benes
  Cc: Joe Lawrence, Kamalesh Babulal, live-patching, linux-kselftest

On Mon 2020-06-15 09:55:27, Miroslav Benes wrote:
> > From
> > https://www.gnu.org/software/grep/manual/grep.html#The-Backslash-Character-and-Special-Expressions
> > :
> > 
> > The ‘\’ character, when followed by certain ordinary characters, takes a
> > special meaning:
> > 
> > ...
> > 
> > ‘\<’
> > 
> >     Match the empty string at the beginning of word.
> > ‘\>’
> > 
> >     Match the empty string at the end of word.

The description is a bit confusing. I wonder how it handles dot,
comma, or colon. They are neither empty or word characters.

> > 
> > I'd be happy to use any other (more readable!) whole-word matching grep trick,
> > this \<one\> just happens to be committed to my cmdline muscle memory.
> 
> There is 'grep -w' which I use for this.

'grep -w' looks good promissing.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 18+ messages in thread

end of thread, other threads:[~2020-06-15  9:19 UTC | newest]

Thread overview: 18+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-06-10 17:20 [PATCH 0/3] selftests/livepatch: small script cleanups Joe Lawrence
2020-06-10 17:20 ` [PATCH 1/3] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
2020-06-11  7:38   ` Miroslav Benes
2020-06-11 13:01     ` Joe Lawrence
2020-06-11 13:06       ` Miroslav Benes
2020-06-12  9:49   ` Petr Mladek
2020-06-14 15:19     ` Joe Lawrence
2020-06-12 10:11   ` Petr Mladek
2020-06-10 17:21 ` [PATCH 2/3] selftests/livepatch: use $(dmesg --notime) instead of manually filtering Joe Lawrence
2020-06-12 10:12   ` Petr Mladek
2020-06-10 17:21 ` [PATCH 3/3] selftests/livepatch: filter 'taints' from dmesg comparison Joe Lawrence
2020-06-11  7:39   ` Miroslav Benes
2020-06-11 13:10     ` Joe Lawrence
2020-06-12 11:47       ` Petr Mladek
2020-06-12 12:57         ` Kamalesh Babulal
2020-06-14 14:45           ` Joe Lawrence
2020-06-15  7:55             ` Miroslav Benes
2020-06-15  9:19               ` Petr Mladek

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).