[PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Michael Ellerman]

It is Very Rude to clear dmesg in test scripts. That's because the
script may be part of a larger test run, and clearing dmesg
potentially destroys the output of other tests.

We can avoid using dmesg -c by saving the content of dmesg before the
test, and then using diff to compare that to the dmesg afterward,
producing a log with just the added lines.

Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>
---
 tools/testing/selftests/lkdtm/run.sh | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
index dadf819148a4..0b409e187c7b 100755
--- a/tools/testing/selftests/lkdtm/run.sh
+++ b/tools/testing/selftests/lkdtm/run.sh
@@ -59,23 +59,25 @@ if [ -z "$expect" ]; then
 	expect="call trace:"
 fi
 
-# Clear out dmesg for output reporting
-dmesg -c >/dev/null
-
 # Prepare log for report checking
-LOG=$(mktemp --tmpdir -t lkdtm-XXXXXX)
+LOG=$(mktemp --tmpdir -t lkdtm-log-XXXXXX)
+DMESG=$(mktemp --tmpdir -t lkdtm-dmesg-XXXXXX)
 cleanup() {
-	rm -f "$LOG"
+	rm -f "$LOG" "$DMESG"
 }
 trap cleanup EXIT
 
+# Save existing dmesg so we can detect new content below
+dmesg > "$DMESG"
+
 # Most shells yell about signals and we're expecting the "cat" process
 # to usually be killed by the kernel. So we have to run it in a sub-shell
 # and silence errors.
 ($SHELL -c 'cat <(echo '"$test"') >'"$TRIGGER" 2>/dev/null) || true
 
 # Record and dump the results
-dmesg -c >"$LOG"
+dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
+
 cat "$LOG"
 # Check for expected output
 if egrep -qi "$expect" "$LOG" ; then

base-commit: 192ffb7515839b1cc8457e0a8c1e09783de019d3
-- 
2.25.1

[PATCH 2/2] selftests/lkdtm: Use grep -E instead of egrep

[Michael Ellerman]

shellcheck complains that egrep is deprecated, and the grep man page
agrees. Use grep -E instead.

Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>
---
 tools/testing/selftests/lkdtm/run.sh | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
index 0b409e187c7b..ee64ff8df8f4 100755
--- a/tools/testing/selftests/lkdtm/run.sh
+++ b/tools/testing/selftests/lkdtm/run.sh
@@ -25,13 +25,13 @@ fi
 # Figure out which test to run from our script name.
 test=$(basename $0 .sh)
 # Look up details about the test from master list of LKDTM tests.
-line=$(egrep '^#?'"$test"'\b' tests.txt)
+line=$(grep -E '^#?'"$test"'\b' tests.txt)
 if [ -z "$line" ]; then
 	echo "Skipped: missing test '$test' in tests.txt"
 	exit $KSELFTEST_SKIP_TEST
 fi
 # Check that the test is known to LKDTM.
-if ! egrep -q '^'"$test"'$' "$TRIGGER" ; then
+if ! grep -E -q '^'"$test"'$' "$TRIGGER" ; then
 	echo "Skipped: test '$test' missing in $TRIGGER!"
 	exit $KSELFTEST_SKIP_TEST
 fi
@@ -80,11 +80,11 @@ dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" -
 
 cat "$LOG"
 # Check for expected output
-if egrep -qi "$expect" "$LOG" ; then
+if grep -E -qi "$expect" "$LOG" ; then
 	echo "$test: saw '$expect': ok"
 	exit 0
 else
-	if egrep -qi XFAIL: "$LOG" ; then
+	if grep -E -qi XFAIL: "$LOG" ; then
 		echo "$test: saw 'XFAIL': [SKIP]"
 		exit $KSELFTEST_SKIP_TEST
 	else
-- 
2.25.1

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Kees Cook]

On Fri, May 08, 2020 at 04:53:55PM +1000, Michael Ellerman wrote:
> It is Very Rude to clear dmesg in test scripts. That's because the
> script may be part of a larger test run, and clearing dmesg
> potentially destroys the output of other tests.
> 
> We can avoid using dmesg -c by saving the content of dmesg before the
> test, and then using diff to compare that to the dmesg afterward,
> producing a log with just the added lines.

Sounds good to me!

> 
> Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>

Acked-by: Kees Cook <keescook@chromium.org>

-- 
Kees Cook

Re: [PATCH 2/2] selftests/lkdtm: Use grep -E instead of egrep

[Kees Cook]

On Fri, May 08, 2020 at 04:53:56PM +1000, Michael Ellerman wrote:
> shellcheck complains that egrep is deprecated, and the grep man page
> agrees. Use grep -E instead.
> 
> Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>

Acked-by: Kees Cook <keescook@chromium.org>

-- 
Kees Cook

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Naresh Kamboju]

On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
>
> It is Very Rude to clear dmesg in test scripts. That's because the
> script may be part of a larger test run, and clearing dmesg
> potentially destroys the output of other tests.
>
> We can avoid using dmesg -c by saving the content of dmesg before the
> test, and then using diff to compare that to the dmesg afterward,
> producing a log with just the added lines.
>
> Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>
> ---
>  tools/testing/selftests/lkdtm/run.sh | 14 ++++++++------
>  1 file changed, 8 insertions(+), 6 deletions(-)
>
> diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
> index dadf819148a4..0b409e187c7b 100755
> --- a/tools/testing/selftests/lkdtm/run.sh
> +++ b/tools/testing/selftests/lkdtm/run.sh
> @@ -59,23 +59,25 @@ if [ -z "$expect" ]; then
>         expect="call trace:"
>  fi
>
> -# Clear out dmesg for output reporting
> -dmesg -c >/dev/null
> -
>  # Prepare log for report checking
> -LOG=$(mktemp --tmpdir -t lkdtm-XXXXXX)
> +LOG=$(mktemp --tmpdir -t lkdtm-log-XXXXXX)
> +DMESG=$(mktemp --tmpdir -t lkdtm-dmesg-XXXXXX)
>  cleanup() {
> -       rm -f "$LOG"
> +       rm -f "$LOG" "$DMESG"
>  }
>  trap cleanup EXIT
>
> +# Save existing dmesg so we can detect new content below
> +dmesg > "$DMESG"
> +
>  # Most shells yell about signals and we're expecting the "cat" process
>  # to usually be killed by the kernel. So we have to run it in a sub-shell
>  # and silence errors.
>  ($SHELL -c 'cat <(echo '"$test"') >'"$TRIGGER" 2>/dev/null) || true
>
>  # Record and dump the results
> -dmesg -c >"$LOG"
> +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true

We are facing problems with the diff `=%>` part of the option.
This report is from the OpenEmbedded environment.
We have the same problem from livepatch_testcases.

# selftests lkdtm BUG.sh
lkdtm: BUG.sh_ #
# diff unrecognized option '--changed-group-format=%>'
unrecognized: option_'--changed-group-format=%>' #
# BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
v1.27.2: (2020-03-30_164108 #
#
: _ #
# Usage diff [-abBdiNqrTstw] [-L LABEL] [-S FILE] [-U LINES] FILE1 FILE2
diff: [-abBdiNqrTstw]_[-L #
# BUG missing 'kernel BUG at' [FAIL]

Full test output log,
https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200621/testrun/2850083/suite/kselftest/test/lkdtm_BUG.sh/log

-- 
Linaro LKFT
https://lkft.linaro.org

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Joe Lawrence]

On 6/22/20 4:51 AM, Naresh Kamboju wrote:
> On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
>>
>> It is Very Rude to clear dmesg in test scripts. That's because the
>> script may be part of a larger test run, and clearing dmesg
>> potentially destroys the output of other tests.
>>
>> We can avoid using dmesg -c by saving the content of dmesg before the
>> test, and then using diff to compare that to the dmesg afterward,
>> producing a log with just the added lines.
>>
>> Signed-off-by: Michael Ellerman <mpe@ellerman.id.au>
>> ---
>>   tools/testing/selftests/lkdtm/run.sh | 14 ++++++++------
>>   1 file changed, 8 insertions(+), 6 deletions(-)
>>
>> diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
>> index dadf819148a4..0b409e187c7b 100755
>> --- a/tools/testing/selftests/lkdtm/run.sh
>> +++ b/tools/testing/selftests/lkdtm/run.sh
>> @@ -59,23 +59,25 @@ if [ -z "$expect" ]; then
>>          expect="call trace:"
>>   fi
>>
>> -# Clear out dmesg for output reporting
>> -dmesg -c >/dev/null
>> -
>>   # Prepare log for report checking
>> -LOG=$(mktemp --tmpdir -t lkdtm-XXXXXX)
>> +LOG=$(mktemp --tmpdir -t lkdtm-log-XXXXXX)
>> +DMESG=$(mktemp --tmpdir -t lkdtm-dmesg-XXXXXX)
>>   cleanup() {
>> -       rm -f "$LOG"
>> +       rm -f "$LOG" "$DMESG"
>>   }
>>   trap cleanup EXIT
>>
>> +# Save existing dmesg so we can detect new content below
>> +dmesg > "$DMESG"
>> +
>>   # Most shells yell about signals and we're expecting the "cat" process
>>   # to usually be killed by the kernel. So we have to run it in a sub-shell
>>   # and silence errors.
>>   ($SHELL -c 'cat <(echo '"$test"') >'"$TRIGGER" 2>/dev/null) || true
>>
>>   # Record and dump the results
>> -dmesg -c >"$LOG"
>> +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> 
> We are facing problems with the diff `=%>` part of the option.
> This report is from the OpenEmbedded environment.
> We have the same problem from livepatch_testcases.
> 
> # selftests lkdtm BUG.sh
> lkdtm: BUG.sh_ #
> # diff unrecognized option '--changed-group-format=%>'
> unrecognized: option_'--changed-group-format=%>' #
> # BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
> v1.27.2: (2020-03-30_164108 #
> #
> : _ #
> # Usage diff [-abBdiNqrTstw] [-L LABEL] [-S FILE] [-U LINES] FILE1 FILE2
> diff: [-abBdiNqrTstw]_[-L #
> # BUG missing 'kernel BUG at' [FAIL]
> 
> Full test output log,
> https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200621/testrun/2850083/suite/kselftest/test/lkdtm_BUG.sh/log
> 

D'oh!  Using diff's changed/unchanged group format was a nice trick to 
easily fetch the new kernel log messages.

I can't think of any simple alternative off the top of my head, so 
here's a kludgy tested-once awk script:

  SAVED_DMESG="$(dmesg | tail -n1)"
  ... tests ...
  NEW_DMESG=$(dmesg | awk -v last="$SAVED_DMESG" 'p; $0 == last{p=1}')

I think timestamps should make each log line unique, but this probably 
won't handle kernel log buffer overflow.

Maybe it would be easier to log a known unique test delimiter msg and 
then fetch all new messages after that?

-- Joe

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Petr Mladek]

On Tue 2020-06-23 23:48:36, Joe Lawrence wrote:
> On 6/22/20 4:51 AM, Naresh Kamboju wrote:
> > On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
> > > 
> > > It is Very Rude to clear dmesg in test scripts. That's because the
> > > script may be part of a larger test run, and clearing dmesg
> > > potentially destroys the output of other tests.
> > > 
> > > We can avoid using dmesg -c by saving the content of dmesg before the
> > > test, and then using diff to compare that to the dmesg afterward,
> > > producing a log with just the added lines.
> > >
> > > > > > diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
> > > index dadf819148a4..0b409e187c7b 100755
> > > --- a/tools/testing/selftests/lkdtm/run.sh
> > > +++ b/tools/testing/selftests/lkdtm/run.sh
> > >   # Record and dump the results
> > > -dmesg -c >"$LOG"
> > > +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> > 
> > We are facing problems with the diff `=%>` part of the option.
> > This report is from the OpenEmbedded environment.
> > We have the same problem from livepatch_testcases.
> > 
> > # selftests lkdtm BUG.sh
> > lkdtm: BUG.sh_ #
> > # diff unrecognized option '--changed-group-format=%>'
> > unrecognized: option_'--changed-group-format=%>' #
> > # BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
> > v1.27.2: (2020-03-30_164108 #
> > #
> > : _ #
> > # Usage diff [-abBdiNqrTstw] [-L LABEL] [-S FILE] [-U LINES] FILE1 FILE2
> > diff: [-abBdiNqrTstw]_[-L #
> > # BUG missing 'kernel BUG at' [FAIL]
> > 
> > Full test output log,
> > https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200621/testrun/2850083/suite/kselftest/test/lkdtm_BUG.sh/log
> > 
> 
> D'oh!  Using diff's changed/unchanged group format was a nice trick to
> easily fetch the new kernel log messages.
> 
> I can't think of any simple alternative off the top of my head, so here's a
> kludgy tested-once awk script:
> 
>  SAVED_DMESG="$(dmesg | tail -n1)"
>  ... tests ...
>  NEW_DMESG=$(dmesg | awk -v last="$SAVED_DMESG" 'p; $0 == last{p=1}')
> 
> I think timestamps should make each log line unique, but this probably won't
> handle kernel log buffer overflow.

The test would fail anyway if there was log buffer overflow.

We could check if the last line was still there and
suggest to increase the log buffer size in the error message.

> Maybe it would be easier to log a known unique test delimiter msg and then
> fetch all new messages after that?

The timestamp should be enough to distinguish any message.

But some visual separator between each test is useful anyway. And
it might include some random string...

Best Regards,
Petr

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Joe Lawrence]

On Wed, Jun 24, 2020 at 10:39:55AM +0200, Petr Mladek wrote:
> On Tue 2020-06-23 23:48:36, Joe Lawrence wrote:
> > On 6/22/20 4:51 AM, Naresh Kamboju wrote:
> > > On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
> > > > 
> > > > It is Very Rude to clear dmesg in test scripts. That's because the
> > > > script may be part of a larger test run, and clearing dmesg
> > > > potentially destroys the output of other tests.
> > > > 
> > > > We can avoid using dmesg -c by saving the content of dmesg before the
> > > > test, and then using diff to compare that to the dmesg afterward,
> > > > producing a log with just the added lines.
> > > >
> > > > > > > diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
> > > > index dadf819148a4..0b409e187c7b 100755
> > > > --- a/tools/testing/selftests/lkdtm/run.sh
> > > > +++ b/tools/testing/selftests/lkdtm/run.sh
> > > >   # Record and dump the results
> > > > -dmesg -c >"$LOG"
> > > > +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> > > 
> > > We are facing problems with the diff `=%>` part of the option.
> > > This report is from the OpenEmbedded environment.
> > > We have the same problem from livepatch_testcases.
> > > 
> > > # selftests lkdtm BUG.sh
> > > lkdtm: BUG.sh_ #
> > > # diff unrecognized option '--changed-group-format=%>'
> > > unrecognized: option_'--changed-group-format=%>' #
> > > # BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
> > > v1.27.2: (2020-03-30_164108 #
> > > #
> > > : _ #
> > > # Usage diff [-abBdiNqrTstw] [-L LABEL] [-S FILE] [-U LINES] FILE1 FILE2
> > > diff: [-abBdiNqrTstw]_[-L #
> > > # BUG missing 'kernel BUG at' [FAIL]
> > > 
> > > Full test output log,
> > > https://qa-reports.linaro.org/lkft/linux-next-oe/build/next-20200621/testrun/2850083/suite/kselftest/test/lkdtm_BUG.sh/log
> > > 
> > 
> > D'oh!  Using diff's changed/unchanged group format was a nice trick to
> > easily fetch the new kernel log messages.
> > 
> > I can't think of any simple alternative off the top of my head, so here's a
> > kludgy tested-once awk script:
> > 
> >  SAVED_DMESG="$(dmesg | tail -n1)"
> >  ... tests ...
> >  NEW_DMESG=$(dmesg | awk -v last="$SAVED_DMESG" 'p; $0 == last{p=1}')
> > 
> > I think timestamps should make each log line unique, but this probably won't
> > handle kernel log buffer overflow.
> 
> The test would fail anyway if there was log buffer overflow.
> 
> We could check if the last line was still there and
> suggest to increase the log buffer size in the error message.
> 

Hi Petr,

This is a good suggestion and I've worked it into the awk script I
wrote last night, check it out at the bottom ...

> > Maybe it would be easier to log a known unique test delimiter msg and then
> > fetch all new messages after that?
> 
> The timestamp should be enough to distinguish any message.
> 
> But some visual separator between each test is useful anyway. And
> it might include some random string...
> 

Ah yeah, you're right about those timestamps again. :)

As for separators, we've already added the "===== TEST: foo =====" for
the livepatch ones... so I think with the timestamp prefix, we're good
enough, no?


I did a bit more hacking to work that awk script into the livepatching
tests.  The changes aren't too bad and coding it ourselves lets us drop
the temporary dmesg file business.  If this looks good, I can send out
as a real patch, but then that raises a few questions:

  1 - f131d9edc29d ("selftests/lkdtm: Don't clear dmesg when running
      tests") has already merged, updating that file doesn't look too
      difficult, but will need a Fixes tag and should probably go
      through Shuah's tree.

  2 - We haven't actually merged the livepatch copy yet.  I can roll
      another version of that patchset, substituting a fix for the
      problematic patch, or we could just tack this one on at the end.
      In fine with either approach.

-- Joe

-->8-- -->8-- -->8-- -->8-- -->8-- -->8-- -->8-- -->8-- -->8-- -->8--


From 892a651839ac6cdd398d6d9998c0d2e4214b72f7 Mon Sep 17 00:00:00 2001
From: Joe Lawrence <joe.lawrence@redhat.com>
Date: Wed, 24 Jun 2020 15:34:04 -0400
Subject: [PATCH] selftests/livepatch: support BusyBox diff

BusyBox diff doesn't support the GNU diff '--LTYPE-line-format' options
that were used in the selftests to filter older kernel log messages from
dmesg output.

Bite the bullet and code this into the selftest:

  - test start: remember the last dmesg entry (has unique [timestamp]
    prefix) in $SAVED_DMESG
  - test end: awk-filter dmesg output up to and including $SAVED_DMESG

Account for kernel log overflow in case awk doesn't find $SAVED_DMESG,
exit and fail the test with a recommendation that the user expand the
kernel log buffer.

Reported-by: Naresh Kamboju <naresh.kamboju@linaro.org>
Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
---
 tools/testing/selftests/livepatch/functions.sh | 18 ++++++++----------
 1 file changed, 8 insertions(+), 10 deletions(-)

diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
index 36648ca367c2..365ce4110265 100644
--- a/tools/testing/selftests/livepatch/functions.sh
+++ b/tools/testing/selftests/livepatch/functions.sh
@@ -41,15 +41,16 @@ function die() {
 	exit 1
 }
 
-# save existing dmesg so we can detect new content
+# save last dmesg entry so we can detect new content
 function save_dmesg() {
-	SAVED_DMESG=$(mktemp --tmpdir -t klp-dmesg-XXXXXX)
-	dmesg > "$SAVED_DMESG"
+	SAVED_DMESG="$(dmesg | tail -n1)"
 }
 
-# cleanup temporary dmesg file from save_dmesg()
-function cleanup_dmesg_file() {
-	rm -f "$SAVED_DMESG"
+# filter all dmesg content before and including $SAVED_DMESG
+function new_dmesg() {
+	if ! dmesg | awk -v last="$SAVED_DMESG" 'p; $0 == last{p=1} END {exit !p}'; then
+		die "dmesg overflow, try increasing kernel log buffer size"
+	fi
 }
 
 function push_config() {
@@ -81,7 +82,6 @@ function set_ftrace_enabled() {
 
 function cleanup() {
 	pop_config
-	cleanup_dmesg_file
 }
 
 # setup_config - save the current config and set a script exit trap that
@@ -277,7 +277,7 @@ function check_result {
 	# help differentiate repeated testing runs.  Remove them with a
 	# post-comparison sed filter.
 
-	result=$(dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$SAVED_DMESG" - | \
+	result=$(new_dmesg | \
 		 grep -e 'livepatch:' -e 'test_klp' | \
 		 grep -v '\(tainting\|taints\) kernel' | \
 		 sed 's/^\[[ 0-9.]*\] //')
@@ -288,6 +288,4 @@ 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
-
-	cleanup_dmesg_file
 }
-- 
2.21.3

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Kees Cook]

On Mon, Jun 22, 2020 at 02:21:38PM +0530, Naresh Kamboju wrote:
> On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
> >  # Record and dump the results
> > -dmesg -c >"$LOG"
> > +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> 
> We are facing problems with the diff `=%>` part of the option.
> This report is from the OpenEmbedded environment.
> We have the same problem from livepatch_testcases.

Does "comm" exists in those environments?

dmesg | comm -13 "$DMESG" - > "$LOG" || true

this is even shorter than the diff command line. :)

-- 
Kees Cook

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Petr Mladek]

On Wed 2020-06-24 16:12:47, Joe Lawrence wrote:
> On Wed, Jun 24, 2020 at 10:39:55AM +0200, Petr Mladek wrote:
> > On Tue 2020-06-23 23:48:36, Joe Lawrence wrote:
> > > On 6/22/20 4:51 AM, Naresh Kamboju wrote:
> > > > On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
> > > > > 
> > > > > It is Very Rude to clear dmesg in test scripts. That's because the
> > > > > script may be part of a larger test run, and clearing dmesg
> > > > > potentially destroys the output of other tests.
> > > > > 
> > > > > We can avoid using dmesg -c by saving the content of dmesg before the
> > > > > test, and then using diff to compare that to the dmesg afterward,
> > > > > producing a log with just the added lines.
> > > > >
> > > > > > > > diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
> > > > > index dadf819148a4..0b409e187c7b 100755
> > > > > --- a/tools/testing/selftests/lkdtm/run.sh
> > > > > +++ b/tools/testing/selftests/lkdtm/run.sh
> > > > >   # Record and dump the results
> > > > > -dmesg -c >"$LOG"
> > > > > +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> > > > 
> > > > We are facing problems with the diff `=%>` part of the option.
> > > > This report is from the OpenEmbedded environment.
> > > > We have the same problem from livepatch_testcases.
> > > > 
> > > > # selftests lkdtm BUG.sh
> > > > lkdtm: BUG.sh_ #
> > > > # diff unrecognized option '--changed-group-format=%>'
> > > > unrecognized: option_'--changed-group-format=%>' #
> > > > # BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
> > > > v1.27.2: (2020-03-30_164108 #

> I did a bit more hacking to work that awk script into the livepatching
> tests.  The changes aren't too bad and coding it ourselves lets us drop
> the temporary dmesg file business.  If this looks good, I can send out
> as a real patch, but then that raises a few questions:

The patch worked and I agree that it is not that bad.

Well, what about using "comm" as proposed by Michael in the other
mail? It seems to be part of coreutils and should be everywhere.

I guess that many people, including me, are not fluent in awk.
So, I am slightly in favor of the "comm" approach ;-)


>   1 - f131d9edc29d ("selftests/lkdtm: Don't clear dmesg when running
>       tests") has already merged, updating that file doesn't look too
>       difficult, but will need a Fixes tag and should probably go
>       through Shuah's tree.

Yup.

>   2 - We haven't actually merged the livepatch copy yet.  I can roll
>       another version of that patchset, substituting a fix for the
>       problematic patch, or we could just tack this one on at the end.
>       In fine with either approach.

I prefer the followup patch to avoid rebase.

Best Regards,
Petr

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Joe Lawrence]

On 6/26/20 4:02 AM, Petr Mladek wrote:
> On Wed 2020-06-24 16:12:47, Joe Lawrence wrote:
>> On Wed, Jun 24, 2020 at 10:39:55AM +0200, Petr Mladek wrote:
>>> On Tue 2020-06-23 23:48:36, Joe Lawrence wrote:
>>>> On 6/22/20 4:51 AM, Naresh Kamboju wrote:
>>>>> On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
>>>>>>
>>>>>> It is Very Rude to clear dmesg in test scripts. That's because the
>>>>>> script may be part of a larger test run, and clearing dmesg
>>>>>> potentially destroys the output of other tests.
>>>>>>
>>>>>> We can avoid using dmesg -c by saving the content of dmesg before the
>>>>>> test, and then using diff to compare that to the dmesg afterward,
>>>>>> producing a log with just the added lines.
>>>>>>
>>>>>>>>> diff --git a/tools/testing/selftests/lkdtm/run.sh b/tools/testing/selftests/lkdtm/run.sh
>>>>>> index dadf819148a4..0b409e187c7b 100755
>>>>>> --- a/tools/testing/selftests/lkdtm/run.sh
>>>>>> +++ b/tools/testing/selftests/lkdtm/run.sh
>>>>>>    # Record and dump the results
>>>>>> -dmesg -c >"$LOG"
>>>>>> +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
>>>>>
>>>>> We are facing problems with the diff `=%>` part of the option.
>>>>> This report is from the OpenEmbedded environment.
>>>>> We have the same problem from livepatch_testcases.
>>>>>
>>>>> # selftests lkdtm BUG.sh
>>>>> lkdtm: BUG.sh_ #
>>>>> # diff unrecognized option '--changed-group-format=%>'
>>>>> unrecognized: option_'--changed-group-format=%>' #
>>>>> # BusyBox v1.27.2 (2020-03-30 164108 UTC) multi-call binary.
>>>>> v1.27.2: (2020-03-30_164108 #
> 
>> I did a bit more hacking to work that awk script into the livepatching
>> tests.  The changes aren't too bad and coding it ourselves lets us drop
>> the temporary dmesg file business.  If this looks good, I can send out
>> as a real patch, but then that raises a few questions:
> 
> The patch worked and I agree that it is not that bad.
> 
> Well, what about using "comm" as proposed by Michael in the other
> mail? It seems to be part of coreutils and should be everywhere.
> 
> I guess that many people, including me, are not fluent in awk.
> So, I am slightly in favor of the "comm" approach ;-)
> 

comm is definitely simpler and for some reason I forgot about the 
leading timestamps (again!) dismissing it thinking that the inputs 
weren't sorted.  But luckily they are and if Naresh or anyone can 
confirm that comm is well supported in the BusyBox testing environment, 
then using that is fine w/me.

-- Joe

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Naresh Kamboju]

On Thu, 25 Jun 2020 at 11:46, Kees Cook <keescook@chromium.org> wrote:
>
> On Mon, Jun 22, 2020 at 02:21:38PM +0530, Naresh Kamboju wrote:
> > On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@ellerman.id.au> wrote:
> > >  # Record and dump the results
> > > -dmesg -c >"$LOG"
> > > +dmesg | diff --changed-group-format='%>' --unchanged-group-format='' "$DMESG" - > "$LOG" || true
> >
> > We are facing problems with the diff `=%>` part of the option.
> > This report is from the OpenEmbedded environment.
> > We have the same problem from livepatch_testcases.
>
> Does "comm" exists in those environments?
>
> dmesg | comm -13 "$DMESG" - > "$LOG" || true

"comm" works in our environment.

- Naresh

Re: [PATCH 1/2] selftests/lkdtm: Don't clear dmesg when running tests

[Naresh Kamboju]

> > Well, what about using "comm" as proposed by Michael in the other
> > mail? It seems to be part of coreutils and should be everywhere.
> >
> > I guess that many people, including me, are not fluent in awk.
> > So, I am slightly in favor of the "comm" approach ;-)
> >
>
> comm is definitely simpler and for some reason I forgot about the
> leading timestamps (again!) dismissing it thinking that the inputs
> weren't sorted.  But luckily they are and if Naresh or anyone can
> confirm that comm is well supported in the BusyBox testing environment,
> then using that is fine w/me.

"comm" works in our environment.

- Naresh