[PATCH v3] rcutorture: Copy out ftrace into its own console file

[PATCH v3] rcutorture: Copy out ftrace into its own console file

[Joel Fernandes (Google)]

When debugging, it can be difficult to quickly find the ftrace dump
within the console log, which in turn makes it difficult to process it
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.

Also handle the case of multiple ftrace dumps potentially showing up in the
log. Example for a file like [1], it will extract as [2].

[1]:
foo
foo
Dumping ftrace buffer:
---------------------------------
blah
blah
---------------------------------
more
bar
baz
Dumping ftrace buffer:
---------------------------------
blah2
blah2
---------------------------------
bleh
bleh

[2]:

Ftrace dump 1:
blah
blah

Ftrace dump 2:
blah2
blah2


Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
---
v2->v3: Updates from Paul. Also handle multiple ftrace dumps.

 .../selftests/rcutorture/bin/functions.sh     | 24 +++++++++++++++++++
 .../selftests/rcutorture/bin/parse-console.sh |  7 ++++++
 2 files changed, 31 insertions(+)
 mode change 100644 => 100755 tools/testing/selftests/rcutorture/bin/functions.sh

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..a5c74e508e41
--- a/tools/testing/selftests/rcutorture/bin/functions.sh
+++ b/tools/testing/selftests/rcutorture/bin/functions.sh
@@ -331,3 +331,30 @@ specify_qemu_net () {
 		echo $1 -net none
 	fi
 }
+
+# Extract the ftrace output from the console log output
+# The ftrace output in the original logs look like:
+# Dumping ftrace buffer:
+# ---------------------------------
+# [...]
+# ---------------------------------
+extract_ftrace_from_console() {
+        awk '
+        /Dumping ftrace buffer:/ {
+        buffer_count++
+        print "Ftrace dump " buffer_count ":"
+        capture = 1
+        next
+    }
+    /---------------------------------/ {
+        if(capture == 1) {
+            capture = 2
+            next
+        } else if(capture == 2) {
+            capture = 0
+            print ""
+        }
+    }
+    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
-- 
2.41.0.694.ge786442a9b-goog

Re: [PATCH v3] rcutorture: Copy out ftrace into its own console file

[Paul E. McKenney]

On Tue, Aug 15, 2023 at 07:09:49PM +0000, Joel Fernandes (Google) wrote:
> When debugging, it can be difficult to quickly find the ftrace dump
> within the console log, which in turn makes it difficult to process it
> 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.
> 
> Also handle the case of multiple ftrace dumps potentially showing up in the
> log. Example for a file like [1], it will extract as [2].
> 
> [1]:
> foo
> foo
> Dumping ftrace buffer:
> ---------------------------------
> blah
> blah
> ---------------------------------
> more
> bar
> baz
> Dumping ftrace buffer:
> ---------------------------------
> blah2
> blah2
> ---------------------------------
> bleh
> bleh
> 
> [2]:
> 
> Ftrace dump 1:
> blah
> blah
> 
> Ftrace dump 2:
> blah2
> blah2
> 
> 
> Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>

Very good, and I did queue this one.

I fixed the indentation of the awk script.  Perhaps your text editor is
being too smart for our good?  ;-)

							Thanx, Paul

> Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
> ---
> v2->v3: Updates from Paul. Also handle multiple ftrace dumps.
> 
>  .../selftests/rcutorture/bin/functions.sh     | 24 +++++++++++++++++++
>  .../selftests/rcutorture/bin/parse-console.sh |  7 ++++++
>  2 files changed, 31 insertions(+)
>  mode change 100644 => 100755 tools/testing/selftests/rcutorture/bin/functions.sh
> 
> 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..a5c74e508e41
> --- a/tools/testing/selftests/rcutorture/bin/functions.sh
> +++ b/tools/testing/selftests/rcutorture/bin/functions.sh
> @@ -331,3 +331,30 @@ specify_qemu_net () {
>  		echo $1 -net none
>  	fi
>  }
> +
> +# Extract the ftrace output from the console log output
> +# The ftrace output in the original logs look like:
> +# Dumping ftrace buffer:
> +# ---------------------------------
> +# [...]
> +# ---------------------------------
> +extract_ftrace_from_console() {
> +        awk '
> +        /Dumping ftrace buffer:/ {
> +        buffer_count++
> +        print "Ftrace dump " buffer_count ":"
> +        capture = 1
> +        next
> +    }
> +    /---------------------------------/ {
> +        if(capture == 1) {
> +            capture = 2
> +            next
> +        } else if(capture == 2) {
> +            capture = 0
> +            print ""
> +        }
> +    }
> +    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
> -- 
> 2.41.0.694.ge786442a9b-goog
> 

Re: [PATCH v3] rcutorture: Copy out ftrace into its own console file

[Joel Fernandes]

On Wed, Aug 16, 2023 at 6:57 PM Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Tue, Aug 15, 2023 at 07:09:49PM +0000, Joel Fernandes (Google) wrote:
> > When debugging, it can be difficult to quickly find the ftrace dump
> > within the console log, which in turn makes it difficult to process it
> > 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.
> >
> > Also handle the case of multiple ftrace dumps potentially showing up in the
> > log. Example for a file like [1], it will extract as [2].
> >
> > [1]:
> > foo
> > foo
> > Dumping ftrace buffer:
> > ---------------------------------
> > blah
> > blah
> > ---------------------------------
> > more
> > bar
> > baz
> > Dumping ftrace buffer:
> > ---------------------------------
> > blah2
> > blah2
> > ---------------------------------
> > bleh
> > bleh
> >
> > [2]:
> >
> > Ftrace dump 1:
> > blah
> > blah
> >
> > Ftrace dump 2:
> > blah2
> > blah2
> >
> >
> > Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
>
> Very good, and I did queue this one.
>
> I fixed the indentation of the awk script.  Perhaps your text editor is
> being too smart for our good?  ;-)

Thanks!  Yes the editor messing up is a possibility, I'll go look at
that, though the indent seems still messed up in your dev branch:

The line "/Dumping ftrace buffer:/ " has spaces, as does the "awk <
$1" line. Is that intentional?  All the following ones have tabs.

thanks,

 - Joel

Re: [PATCH v3] rcutorture: Copy out ftrace into its own console file

[Paul E. McKenney]

On Wed, Aug 16, 2023 at 07:27:03PM -0400, Joel Fernandes wrote:
> On Wed, Aug 16, 2023 at 6:57 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> >
> > On Tue, Aug 15, 2023 at 07:09:49PM +0000, Joel Fernandes (Google) wrote:
> > > When debugging, it can be difficult to quickly find the ftrace dump
> > > within the console log, which in turn makes it difficult to process it
> > > 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.
> > >
> > > Also handle the case of multiple ftrace dumps potentially showing up in the
> > > log. Example for a file like [1], it will extract as [2].
> > >
> > > [1]:
> > > foo
> > > foo
> > > Dumping ftrace buffer:
> > > ---------------------------------
> > > blah
> > > blah
> > > ---------------------------------
> > > more
> > > bar
> > > baz
> > > Dumping ftrace buffer:
> > > ---------------------------------
> > > blah2
> > > blah2
> > > ---------------------------------
> > > bleh
> > > bleh
> > >
> > > [2]:
> > >
> > > Ftrace dump 1:
> > > blah
> > > blah
> > >
> > > Ftrace dump 2:
> > > blah2
> > > blah2
> > >
> > >
> > > Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
> >
> > Very good, and I did queue this one.
> >
> > I fixed the indentation of the awk script.  Perhaps your text editor is
> > being too smart for our good?  ;-)
> 
> Thanks!  Yes the editor messing up is a possibility, I'll go look at
> that, though the indent seems still messed up in your dev branch:
> 
> The line "/Dumping ftrace buffer:/ " has spaces, as does the "awk <
> $1" line. Is that intentional?  All the following ones have tabs.

Not intentional at all, thank you for catching it!

How about the fixup patch shown below, to be merged into the current
commit?

							Thanx, Paul

------------------------------------------------------------------------

commit 2322b84997c61e98bd48369f12c9b83b6e0d0ffb
Author: Paul E. McKenney <paulmck@kernel.org>
Date:   Wed Aug 16 16:44:49 2023 -0700

    fixup! rcutorture: Copy out ftrace into its own console file
    
    Signed-off-by: Paul E. McKenney <paulmck@kernel.org>

diff --git a/tools/testing/selftests/rcutorture/bin/functions.sh b/tools/testing/selftests/rcutorture/bin/functions.sh
index 1ac86f68a436..6e415ddb206f 100755
--- a/tools/testing/selftests/rcutorture/bin/functions.sh
+++ b/tools/testing/selftests/rcutorture/bin/functions.sh
@@ -339,9 +339,9 @@ specify_qemu_net () {
 # [...]
 # ---------------------------------
 extract_ftrace_from_console() {
-        awk < "$1" '
+	awk < "$1" '
 
-        /Dumping ftrace buffer:/ {
+	/Dumping ftrace buffer:/ {
 		buffer_count++
 		print "Ftrace dump " buffer_count ":"
 		capture = 1

Re: [PATCH v3] rcutorture: Copy out ftrace into its own console file

[Joel Fernandes]

On Wed, Aug 16, 2023 at 7:46 PM Paul E. McKenney <paulmck@kernel.org> wrote:
>
> On Wed, Aug 16, 2023 at 07:27:03PM -0400, Joel Fernandes wrote:
> > On Wed, Aug 16, 2023 at 6:57 PM Paul E. McKenney <paulmck@kernel.org> wrote:
> > >
> > > On Tue, Aug 15, 2023 at 07:09:49PM +0000, Joel Fernandes (Google) wrote:
> > > > When debugging, it can be difficult to quickly find the ftrace dump
> > > > within the console log, which in turn makes it difficult to process it
> > > > 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.
> > > >
> > > > Also handle the case of multiple ftrace dumps potentially showing up in the
> > > > log. Example for a file like [1], it will extract as [2].
> > > >
> > > > [1]:
> > > > foo
> > > > foo
> > > > Dumping ftrace buffer:
> > > > ---------------------------------
> > > > blah
> > > > blah
> > > > ---------------------------------
> > > > more
> > > > bar
> > > > baz
> > > > Dumping ftrace buffer:
> > > > ---------------------------------
> > > > blah2
> > > > blah2
> > > > ---------------------------------
> > > > bleh
> > > > bleh
> > > >
> > > > [2]:
> > > >
> > > > Ftrace dump 1:
> > > > blah
> > > > blah
> > > >
> > > > Ftrace dump 2:
> > > > blah2
> > > > blah2
> > > >
> > > >
> > > > Signed-off-by: Joel Fernandes (Google) <joel@joelfernandes.org>
> > >
> > > Very good, and I did queue this one.
> > >
> > > I fixed the indentation of the awk script.  Perhaps your text editor is
> > > being too smart for our good?  ;-)
> >
> > Thanks!  Yes the editor messing up is a possibility, I'll go look at
> > that, though the indent seems still messed up in your dev branch:
> >
> > The line "/Dumping ftrace buffer:/ " has spaces, as does the "awk <
> > $1" line. Is that intentional?  All the following ones have tabs.
>
> Not intentional at all, thank you for catching it!
>
> How about the fixup patch shown below, to be merged into the current
> commit?

Looks good to me, thanks!

 - Joel



>
>                                                         Thanx, Paul
>
> ------------------------------------------------------------------------
>
> commit 2322b84997c61e98bd48369f12c9b83b6e0d0ffb
> Author: Paul E. McKenney <paulmck@kernel.org>
> Date:   Wed Aug 16 16:44:49 2023 -0700
>
>     fixup! rcutorture: Copy out ftrace into its own console file
>
>     Signed-off-by: Paul E. McKenney <paulmck@kernel.org>
>
> diff --git a/tools/testing/selftests/rcutorture/bin/functions.sh b/tools/testing/selftests/rcutorture/bin/functions.sh
> index 1ac86f68a436..6e415ddb206f 100755
> --- a/tools/testing/selftests/rcutorture/bin/functions.sh
> +++ b/tools/testing/selftests/rcutorture/bin/functions.sh
> @@ -339,9 +339,9 @@ specify_qemu_net () {
>  # [...]
>  # ---------------------------------
>  extract_ftrace_from_console() {
> -        awk < "$1" '
> +       awk < "$1" '
>
> -        /Dumping ftrace buffer:/ {
> +       /Dumping ftrace buffer:/ {
>                 buffer_count++
>                 print "Ftrace dump " buffer_count ":"
>                 capture = 1