On 6/22/20 4:51 AM, Naresh Kamboju wrote:
On Fri, 8 May 2020 at 12:23, Michael Ellerman <mpe@xxxxxxxxxxxxxx> 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@xxxxxxxxxxxxxx>
---
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
