On Mon, Aug 14, 2023 at 06:03:24PM -0400, Joel Fernandes wrote:
> On Mon, Aug 14, 2023 at 5:27 PM Paul E. McKenney <paulmck@xxxxxxxxxx> wrote:
> >
> > On Sun, Aug 13, 2023 at 08:36:02PM +0000, Joel Fernandes (Google) wrote:
> > > From: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
> > >
> > > Often times during debugging, it is difficult to jump to the ftrace dump
> > > in the console log and treat it independent of the result of the log file.
> > > Copy the contents of the buffers into its own file to make it easier to refer
> > > to the ftrace dump. The original ftrace dump is still available in the
> > > console log if it is desired to refer to it there.
> > >
> > > Signed-off-by: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
> >
> > Queued, thank you! I did the usual wordsmithing, please see below.
> >
> > I also fixed up the indentation and spacing. I don't know about you,
> > but the initial format made that a bit hard for me to read. ;-)
> >
> > If there are multiple ftrace dumps in a given console.log file, this
> > will concatenate them. Is that the intent?
>
> How would you have multiple dumps, do you mean from subsequent
> (re)boots? If so, yes I am OK with that. I usually look at the latest
> boot attempt.
Fair, but how would you separate out the ftrace dump for the most
recent kernel boot? (Though please see below.)
> I was also thinking of us stopping boot loops. For example, if there
> is a kernel issue and the system keeps rebooting, it will run forever
> in the boot loop silently. It would be good for monitoring of
> console.log and kill the test if the console.log is acting 'weird'.
> Also it would be good if the console.log had a huge timestamp gap in
> it like the TREE04 issue. Would such changes be good to make? I can
> attempt something.
Boot loops can indeed be irritating. So I created this commit:
10f84c2cfb50 ("torture: Avoid torture-test reboot loops")
This passes -no-reboot to qemu, which causes qemu to just stop when
it would otherwise reboot. Much nicer!
The multiple-ftrace-dump issue could still appear should some torture
test decide to turn tracing back on at some point, perhaps in response
to a yet-as-unthought-of module parameter.
Should this ever be a problem, one approach would be to leave the
beginning/end markers and/or number them.
> > commit ce1cf26540b96fc52aec6f6f8e365960ca79a0ad
> > Author: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
> > Date: Sun Aug 13 20:36:02 2023 +0000
> >
> > rcutorture: Copy out ftrace into its own console file
> >
> > When debugging it can be difficult to quickly find the ftrace dump
> > withiin the console log, which in turn makes it difficult to process it
>
> Nit: within.
Ouch, will fix on next rebase.
> > independent of the result of the console output. This commit therefore
> > copies the contents of the buffers into its own file to make it easier
> > to locate and process the ftrace dump. The original ftrace dump is still
> > available in the console log in cases where it is more convenient to
> > process it there, for example, when you have a script that processes
> > console output as well as ftrace-dump data.
> >
> > Signed-off-by: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
> > Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxx>
> >
> > diff --git a/tools/testing/selftests/rcutorture/bin/functions.sh b/tools/testing/selftests/rcutorture/bin/functions.sh
> > old mode 100644
> > new mode 100755
> > index b8e2ea23cb3f..40bcddf5f197
> > --- a/tools/testing/selftests/rcutorture/bin/functions.sh
> > +++ b/tools/testing/selftests/rcutorture/bin/functions.sh
> > @@ -331,3 +331,27 @@ specify_qemu_net () {
> > echo $1 -net none
> > fi
> > }
> > +
> > +# Extract the ftrace output from the console log output
> > +# The ftrace output looks in the logs looks like:
>
> My bad: s/output looks/output/
Will fix on next rebase.
It is the "simple" ones that bite you! ;-)
Thanx, Paul
> Thanks,
>
> - Joel
>
>
> > +# Dumping ftrace buffer:
> > +# ---------------------------------
> > +# [...]
> > +# ---------------------------------
> > +extract_ftrace_from_console() {
> > + awk '
> > + /Dumping ftrace buffer:/ {
> > + capture = 1
> > + next
> > + }
> > + /---------------------------------/ {
> > + if (capture == 1) {
> > + capture = 2
> > + next
> > + } else if (capture == 2) {
> > + capture = 0
> > + }
> > + }
> > + capture == 2
> > + ' "$1";
> > +}
> > diff --git a/tools/testing/selftests/rcutorture/bin/parse-console.sh b/tools/testing/selftests/rcutorture/bin/parse-console.sh
> > index 9ab0f6bc172c..e3d2f69ec0fb 100755
> > --- a/tools/testing/selftests/rcutorture/bin/parse-console.sh
> > +++ b/tools/testing/selftests/rcutorture/bin/parse-console.sh
> > @@ -182,3 +182,10 @@ if ! test -s $file.diags
> > then
> > rm -f $file.diags
> > fi
> > +
> > +# Call extract_ftrace_from_console function, if the output is empty,
> > +# don't create $file.ftrace. Otherwise output the results to $file.ftrace
> > +extract_ftrace_from_console $file > $file.ftrace
> > +if [ ! -s $file.ftrace ]; then
> > + rm -f $file.ftrace
> > +fi
