live-patching.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Petr Mladek <pmladek@suse.com>
To: Joe Lawrence <joe.lawrence@redhat.com>
Cc: live-patching@vger.kernel.org, linux-kselftest@vger.kernel.org,
	Kamalesh Babulal <kamalesh@linux.vnet.ibm.com>,
	Miroslav Benes <mbenes@suse.cz>
Subject: Re: [PATCH v2 2/4] selftests/livepatch: use $(dmesg --notime) instead of manually filtering
Date: Wed, 17 Jun 2020 11:23:52 +0200	[thread overview]
Message-ID: <20200617092352.GT31238@alley> (raw)
In-Reply-To: <20200615172756.12912-3-joe.lawrence@redhat.com>

On Mon 2020-06-15 13:27:54, 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.

I wanted to push this patchset and run full test after each patch.
Suddenly the tests started to fail, for example:

$/tools/testing/selftests/livepatch> ./test-livepatch.sh
TEST: basic function patching ... ok
TEST: multiple livepatches ... not ok

--- expected
+++ result
@@ -1,3 +1,9 @@
+% echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
+livepatch: 'test_klp_livepatch': initializing unpatching transition
+livepatch: 'test_klp_livepatch': starting unpatching transition
+livepatch: 'test_klp_livepatch': completing unpatching transition
+livepatch: 'test_klp_livepatch': unpatching complete
+% rmmod test_klp_livepatch
 % modprobe test_klp_livepatch
 livepatch: enabling patch 'test_klp_livepatch'
 livepatch: 'test_klp_livepatch': initializing patching transition
@@ -20,9 +26,3 @@ livepatch: 'test_klp_atomic_replace': co
 livepatch: 'test_klp_atomic_replace': unpatching complete
 % rmmod test_klp_atomic_replace
 test_klp_livepatch: this has been live patched
-% echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
-livepatch: 'test_klp_livepatch': initializing unpatching transition
-livepatch: 'test_klp_livepatch': starting unpatching transition
-livepatch: 'test_klp_livepatch': completing unpatching transition
-livepatch: 'test_klp_livepatch': unpatching complete
-% rmmod test_klp_livepatch

ERROR: livepatch kselftest(s) failed


The problem is a combination of:

  + 1st patch that causes that old kernel messages are not cleared
  + 2nd patch that removes time stamps from the diff
  + lost the oldest messages because internal kernel log buffer overflow
  + run the same tests more times

As a result, the diff might match with an incomplete log from
the previous run.

Everything works when this 2nd patch is not commited. The timestamp
helps to distinguish old and new messages. The lost messages
are ignored thanks to the diff parameters:

       --changed-group-format='%>' --unchanged-group-format=''

If you agree, I'll solve this problem by not committing this patch
into livepatch.git repo.

It would be great to add a comment that the timestamp is actually
important. But it might be done in a followup patch.

Best Regards,
Petr


> --- a/tools/testing/selftests/livepatch/functions.sh
> +++ b/tools/testing/selftests/livepatch/functions.sh
> @@ -272,9 +272,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


  reply	other threads:[~2020-06-17  9:23 UTC|newest]

Thread overview: 11+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2020-06-15 17:27 [PATCH v2 0/4] selftests/livepatch: small script cleanups Joe Lawrence
2020-06-15 17:27 ` [PATCH v2 1/4] selftests/livepatch: Don't clear dmesg when running tests Joe Lawrence
2020-06-15 17:27 ` [PATCH v2 2/4] selftests/livepatch: use $(dmesg --notime) instead of manually filtering Joe Lawrence
2020-06-17  9:23   ` Petr Mladek [this message]
2020-06-17 11:22     ` Joe Lawrence
2020-06-15 17:27 ` [PATCH v2 3/4] selftests/livepatch: refine dmesg 'taints' in dmesg comparison Joe Lawrence
2020-06-15 17:27 ` [PATCH v2 4/4] selftests/livepatch: add test delimiter to dmesg Joe Lawrence
2020-06-16  8:29 ` [PATCH v2 0/4] selftests/livepatch: small script cleanups Kamalesh Babulal
2020-06-16 11:05 ` Miroslav Benes
2020-06-16 14:43 ` Petr Mladek
2020-06-16 15:16 ` Yannick Cote

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20200617092352.GT31238@alley \
    --to=pmladek@suse.com \
    --cc=joe.lawrence@redhat.com \
    --cc=kamalesh@linux.vnet.ibm.com \
    --cc=linux-kselftest@vger.kernel.org \
    --cc=live-patching@vger.kernel.org \
    --cc=mbenes@suse.cz \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
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).