On Mon, Dec 18, 2023 at 05:44:54PM -0500, Joe Lawrence wrote:
Hi Joe!
...
> > If we pre-trim the timestamps, the output is what we expect:
> >
> > $ comm --nocheck-order -13 \
> > <(sed 's/^\[[ 0-9.]*\] //' /tmp/A) \
> > <(sed 's/^\[[ 0-9.]*\] //' /tmp/B)
> > message four
> >
> > however, I'm not sure if that fix would easily apply. It looks like I
> > provided a disclaimer notice in check_result():
> >
> > # Note: when comparing dmesg output, the kernel log timestamps
> > # help differentiate repeated testing runs. Remove them with a
> > # post-comparison sed filter.
> >
> > so I wonder if comm will get confused with repeated selftest runs?
I would think so. AFAICT even a single run would produce duplicate lines.
...
> This is *very* lightly tested, but I thought maybe you could give it a
> spin. Hopefully it's less brittle than diff/comm strategy.
That seems to be working. However, please see below.
...
> @@ -280,7 +268,13 @@ function set_pre_patch_ret {
> function start_test {
> local test="$1"
>
> - save_dmesg
> + # Dump something unique into the dmesg log, then stash the entry
> + # in LAST_DMESG. The check_result() function will use it to
> + # find new kernel messages since the test started.
> + local timestamp="$(date --rfc-3339=ns)"
> + log "livepatch kselftest timestamp: $timestamp"
> + LAST_DMESG=$(dmesg | grep "livepatch kselftest timestamp: $timestamp")
Not sure if it not paranoid mode, but still..
If the 'log' call is guaranteed synced? AKA would 'grep' always catch the line?
And yeah.. if the log output is pushed away (e.g by a crazy-dumping concurrent
logger), then nothing here would work. But this is not a new problem, so just
my two cents.
> echo -n "TEST: $test ... "
> log "===== TEST: $test ====="
> }
Thanks!
