ftrace: Allow enabling of filters via index of available_filter_functions
authorSteven Rostedt (VMware) <rostedt@goodmis.org>
Mon, 11 Feb 2019 20:00:48 +0000 (15:00 -0500)
committerSteven Rostedt (VMware) <rostedt@goodmis.org>
Fri, 15 Feb 2019 18:10:09 +0000 (13:10 -0500)
Enabling of large number of functions by echoing in a large subset of the
functions in available_filter_functions can take a very long time. The
process requires testing all functions registered by the function tracer
(which is in the 10s of thousands), and doing a kallsyms lookup to convert
the ip address into a name, then comparing that name with the string passed
in.

When a function causes the function tracer to crash the system, a binary
bisect of the available_filter_functions can be done to find the culprit.
But this requires passing in half of the functions in
available_filter_functions over and over again, which makes it basically a
O(n^2) operation. With 40,000 functions, that ends up bing 1,600,000,000
opertions! And enabling this can take over 20 minutes.

As a quick speed up, if a number is passed into one of the filter files,
instead of doing a search, it just enables the function at the corresponding
line of the available_filter_functions file. That is:

 # echo 50 > set_ftrace_filter
 # cat set_ftrace_filter
 x86_pmu_commit_txn

 # head -50 available_filter_functions | tail -1
 x86_pmu_commit_txn

This allows setting of half the available_filter_functions to take place in
less than a second!

 # time seq 20000 > set_ftrace_filter
 real    0m0.042s
 user    0m0.005s
 sys     0m0.015s

 # wc -l set_ftrace_filter
 20000 set_ftrace_filter

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Documentation/trace/ftrace.rst
kernel/trace/ftrace.c
kernel/trace/trace.h
kernel/trace/trace_events_filter.c

index 6ce2763..7c5e6d6 100644 (file)
@@ -233,6 +233,12 @@ of ftrace. Here is a list of some of the key files:
        This interface also allows for commands to be used. See the
        "Filter commands" section for more details.
 
+       As a speed up, since processing strings can't be quite expensive
+       and requires a check of all functions registered to tracing, instead
+       an index can be written into this file. A number (starting with "1")
+       written will instead select the same corresponding at the line position
+       of the "available_filter_functions" file.
+
   set_ftrace_notrace:
 
        This has an effect opposite to that of
@@ -2835,6 +2841,38 @@ Produces::
 
 We can see that there's no more lock or preempt tracing.
 
+Selecting function filters via index
+------------------------------------
+
+Because processing of strings is expensive (the address of the function
+needs to be looked up before comparing to the string being passed in),
+an index can be used as well to enable functions. This is useful in the
+case of setting thousands of specific functions at a time. By passing
+in a list of numbers, no string processing will occur. Instead, the function
+at the specific location in the internal array (which corresponds to the
+functions in the "available_filter_functions" file), is selected.
+
+::
+
+  # echo 1 > set_ftrace_filter
+
+Will select the first function listed in "available_filter_functions"
+
+::
+
+  # head -1 available_filter_functions
+  trace_initcall_finish_cb
+
+  # cat set_ftrace_filter
+  trace_initcall_finish_cb
+
+  # head -50 available_filter_functions | tail -1
+  x86_pmu_commit_txn
+
+  # echo 1 50 > set_ftrace_filter
+  # cat set_ftrace_filter
+  trace_initcall_finish_cb
+  x86_pmu_commit_txn
 
 Dynamic ftrace with the function graph tracer
 ---------------------------------------------
index aac7847..fa79323 100644 (file)
@@ -3701,6 +3701,31 @@ enter_record(struct ftrace_hash *hash, struct dyn_ftrace *rec, int clear_filter)
        return ret;
 }
 
+static int
+add_rec_by_index(struct ftrace_hash *hash, struct ftrace_glob *func_g,
+                int clear_filter)
+{
+       long index = simple_strtoul(func_g->search, NULL, 0);
+       struct ftrace_page *pg;
+       struct dyn_ftrace *rec;
+
+       /* The index starts at 1 */
+       if (--index < 0)
+               return 0;
+
+       do_for_each_ftrace_rec(pg, rec) {
+               if (pg->index <= index) {
+                       index -= pg->index;
+                       /* this is a double loop, break goes to the next page */
+                       break;
+               }
+               rec = &pg->records[index];
+               enter_record(hash, rec, clear_filter);
+               return 1;
+       } while_for_each_ftrace_rec();
+       return 0;
+}
+
 static int
 ftrace_match_record(struct dyn_ftrace *rec, struct ftrace_glob *func_g,
                struct ftrace_glob *mod_g, int exclude_mod)
@@ -3769,6 +3794,11 @@ match_records(struct ftrace_hash *hash, char *func, int len, char *mod)
        if (unlikely(ftrace_disabled))
                goto out_unlock;
 
+       if (func_g.type == MATCH_INDEX) {
+               found = add_rec_by_index(hash, &func_g, clear_filter);
+               goto out_unlock;
+       }
+
        do_for_each_ftrace_rec(pg, rec) {
 
                if (rec->flags & FTRACE_FL_DISABLED)
index a34fa5e..ae7df09 100644 (file)
@@ -1459,6 +1459,7 @@ enum regex_type {
        MATCH_MIDDLE_ONLY,
        MATCH_END_ONLY,
        MATCH_GLOB,
+       MATCH_INDEX,
 };
 
 struct regex {
index f052ecb..ade606c 100644 (file)
@@ -825,6 +825,9 @@ enum regex_type filter_parse_regex(char *buff, int len, char **search, int *not)
 
        *search = buff;
 
+       if (isdigit(buff[0]))
+               return MATCH_INDEX;
+
        for (i = 0; i < len; i++) {
                if (buff[i] == '*') {
                        if (!i) {
@@ -862,6 +865,8 @@ static void filter_build_regex(struct filter_pred *pred)
        }
 
        switch (type) {
+       /* MATCH_INDEX should not happen, but if it does, match full */
+       case MATCH_INDEX:
        case MATCH_FULL:
                r->match = regex_match_full;
                break;