ftrace/scripts: Update the instructions for ftrace-bisect.sh

  From: "Steven Rostedt (Google)" <rostedt@goodmis.org>

The instructions for the ftrace-bisect.sh script, which is used to find
what function is being traced that is causing a kernel crash, and possibly
a triple fault reboot, uses the old method. In 5.1, a new feature was
added that let the user write in the index into available_filter_functions
that maps to the function a user wants to set in set_ftrace_filter (or
set_ftrace_notrace). This takes O(1) to set, as suppose to writing a
function name, which takes O(n) (where n is the number of functions in
available_filter_functions).

The ftrace-bisect.sh requires setting half of the functions in
available_filter_functions, which is O(n^2) using the name method to enable
and can take several minutes to complete. The number method is O(n) which
takes less than a second to complete. Using the number method for any
kernel 5.1 and after is the proper way to do the bisect.

Update the usage to reflect the new change, as well as using the
/sys/kernel/tracing path instead of the obsolete debugfs path.

Cc: stable@vger.kernel.org
Fixes: f79b3f338564e ("ftrace: Allow enabling of filters via index of available_filter_functions")
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
 scripts/tracing/ftrace-bisect.sh | 33 ++++++++++++++++++++++++--------
 1 file changed, 25 insertions(+), 8 deletions(-)
  

On Mon, Jan 23, 2023 at 11:22:52AM -0500, Steven Rostedt wrote:
> From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
> 
> The instructions for the ftrace-bisect.sh script, which is used to find
> what function is being traced that is causing a kernel crash, and possibly
> a triple fault reboot, uses the old method. In 5.1, a new feature was
> added that let the user write in the index into available_filter_functions
> that maps to the function a user wants to set in set_ftrace_filter (or
> set_ftrace_notrace). This takes O(1) to set, as suppose to writing a
> function name, which takes O(n) (where n is the number of functions in
> available_filter_functions).
> 
> The ftrace-bisect.sh requires setting half of the functions in
> available_filter_functions, which is O(n^2) using the name method to enable
> and can take several minutes to complete. The number method is O(n) which
> takes less than a second to complete. Using the number method for any
> kernel 5.1 and after is the proper way to do the bisect.
> 
> Update the usage to reflect the new change, as well as using the
> /sys/kernel/tracing path instead of the obsolete debugfs path.
> 
> Cc: stable@vger.kernel.org
> Fixes: f79b3f338564e ("ftrace: Allow enabling of filters via index of available_filter_functions")
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
>  scripts/tracing/ftrace-bisect.sh | 33 ++++++++++++++++++++++++--------
>  1 file changed, 25 insertions(+), 8 deletions(-)
> 
> diff --git a/scripts/tracing/ftrace-bisect.sh b/scripts/tracing/ftrace-bisect.sh
> index 926701162bc8..94ca73930f8a 100755
> --- a/scripts/tracing/ftrace-bisect.sh
> +++ b/scripts/tracing/ftrace-bisect.sh
> @@ -12,7 +12,7 @@
>  #   (note, if this is a problem with function_graph tracing, then simply
>  #    replace "function" with "function_graph" in the following steps).
>  #
> -#  # cd /sys/kernel/debug/tracing
> +#  # cd /sys/kernel/tracing
>  #  # echo schedule > set_ftrace_filter
>  #  # echo function > current_tracer
>  #
> @@ -20,22 +20,39 @@
>  #
>  #  # echo nop > current_tracer
>  #
> -#  # cat available_filter_functions > ~/full-file
> +# Starting with v5.1 this can be done with numbers, making it much faster:
> +#
> +# The old (slow) way, for kernels before v5.1.
> +#
> +# [old-way] # cat available_filter_functions > ~/full-file
> +#
> +# [old-way] *** Note *** this will take several minutes. Setting multiple
> +# [old-way] functions is an O(n^2) operation, and we are dealing with thousands
> +# [old-way] of functions. So go have  coffee, talk with your coworkers, read
> +# [old-way] facebook. And eventually, this operation will end.

Super-trivial nit, but the above step isn't actually that expensive, and it's
the subsequent write to set_ftrace_filter that's going to be slow.

That double spacing in 'go have  coffee' looks odd; is that an old error from
reformatting a line break, and/or a missing 'a' ?

How about:

# [old-way] *** Note *** writing function names to set_ftrace_filter will take
# [old-way] several minutes. Setting multiple functions is an O(n^2) operation,
# [old-way] and we will set thousands of functions. So for subsequent steps,
# [old-way] go have a coffee, talk with your coworkers, read facebook. And
# [old-way] eventually, this operation will end.

... or leave this in place below, and add "If using [old-way] ..." to the start?

Regardless, this looks sensible to me!

Mark.

> +#
> +# The new way (using numbers) is an O(n) operation, and usually takes less than a second.
> +#
> +# seq `wc -l available_filter_functions | cut -d' ' -f1` > ~/full-file
> +#
> +# This will create a sequence of numbers that match the functions in
> +# available_filter_functions, and when echoing in a number into the
> +# set_ftrace_filter file, it will enable the corresponding function in
> +# O(1) time. Making enabling all functions O(n) where n is the number of
> +# functions to enable.
> +#
> +# For either the new or old way, the rest of the operations remain the same.
> +#
>  #  # ftrace-bisect ~/full-file ~/test-file ~/non-test-file
>  #  # cat ~/test-file > set_ftrace_filter
>  #
> -# *** Note *** this will take several minutes. Setting multiple functions is
> -# an O(n^2) operation, and we are dealing with thousands of functions. So go
> -# have  coffee, talk with your coworkers, read facebook. And eventually, this
> -# operation will end.
> -#
>  #  # echo function > current_tracer
>  #
>  # If it crashes, we know that ~/test-file has a bad function.
>  #
>  #   Reboot back to test kernel.
>  #
> -#     # cd /sys/kernel/debug/tracing
> +#     # cd /sys/kernel/tracing
>  #     # mv ~/test-file ~/full-file
>  #
>  # If it didn't crash.
> -- 
> 2.39.0
>
  

On Mon, 23 Jan 2023 16:59:55 +0000
Mark Rutland <mark.rutland@arm.com> wrote:

> > +# The old (slow) way, for kernels before v5.1.
> > +#
> > +# [old-way] # cat available_filter_functions > ~/full-file
> > +#
> > +# [old-way] *** Note *** this will take several minutes. Setting multiple
> > +# [old-way] functions is an O(n^2) operation, and we are dealing with thousands
> > +# [old-way] of functions. So go have  coffee, talk with your coworkers, read
> > +# [old-way] facebook. And eventually, this operation will end.  
> 
> Super-trivial nit, but the above step isn't actually that expensive, and it's
> the subsequent write to set_ftrace_filter that's going to be slow.

How about:

 "*** Note *** this process will take several minutes to update the filters." 


> 
> That double spacing in 'go have  coffee' looks odd; is that an old error from
> reformatting a line break, and/or a missing 'a' ?

I can fix that.

> 
> How about:
> 
> # [old-way] *** Note *** writing function names to set_ftrace_filter will take
> # [old-way] several minutes. Setting multiple functions is an O(n^2) operation,
> # [old-way] and we will set thousands of functions. So for subsequent steps,
> # [old-way] go have a coffee, talk with your coworkers, read facebook. And
> # [old-way] eventually, this operation will end.
> 
> ... or leave this in place below, and add "If using [old-way] ..." to the start?

I wanted to explicitly show that the above is only a reference to the old
way, and leave no doubt about it. It was either doing this or deleting it
completely. I chose to keep it.

> 
> Regardless, this looks sensible to me!

Thanks, I'll send a v2 with the nit updates.

-- Steve
  

On Mon, Jan 23, 2023 at 12:11:47PM -0500, Steven Rostedt wrote:
> On Mon, 23 Jan 2023 16:59:55 +0000
> Mark Rutland <mark.rutland@arm.com> wrote:
> 
> > > +# The old (slow) way, for kernels before v5.1.
> > > +#
> > > +# [old-way] # cat available_filter_functions > ~/full-file
> > > +#
> > > +# [old-way] *** Note *** this will take several minutes. Setting multiple
> > > +# [old-way] functions is an O(n^2) operation, and we are dealing with thousands
> > > +# [old-way] of functions. So go have  coffee, talk with your coworkers, read
> > > +# [old-way] facebook. And eventually, this operation will end.  
> > 
> > Super-trivial nit, but the above step isn't actually that expensive, and it's
> > the subsequent write to set_ftrace_filter that's going to be slow.
> 
> How about:
> 
>  "*** Note *** this process will take several minutes to update the filters." 

Sounds good to me! :)

FWIW, with that:

Acked-by: Mark Rutland <mark.rutland@arm.com>

> > That double spacing in 'go have  coffee' looks odd; is that an old error from
> > reformatting a line break, and/or a missing 'a' ?
> 
> I can fix that.

Thanks!

> > How about:
> > 
> > # [old-way] *** Note *** writing function names to set_ftrace_filter will take
> > # [old-way] several minutes. Setting multiple functions is an O(n^2) operation,
> > # [old-way] and we will set thousands of functions. So for subsequent steps,
> > # [old-way] go have a coffee, talk with your coworkers, read facebook. And
> > # [old-way] eventually, this operation will end.
> > 
> > ... or leave this in place below, and add "If using [old-way] ..." to the start?
> 
> I wanted to explicitly show that the above is only a reference to the old
> way, and leave no doubt about it. It was either doing this or deleting it
> completely. I chose to keep it.

Fair enough!

Mark.