Skip to content

Commit

Permalink
ftrace: Allow enabling of filters via index of available_filter_funct…
Browse files Browse the repository at this point in the history
…ions

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>
  • Loading branch information
Steven Rostedt (VMware) committed Feb 15, 2019
1 parent 85acbb2 commit f79b3f3
Show file tree
Hide file tree
Showing 4 changed files with 74 additions and 0 deletions.
38 changes: 38 additions & 0 deletions Documentation/trace/ftrace.rst
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
---------------------------------------------
Expand Down
30 changes: 30 additions & 0 deletions kernel/trace/ftrace.c
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down
1 change: 1 addition & 0 deletions kernel/trace/trace.h
Original file line number Diff line number Diff line change
Expand Up @@ -1459,6 +1459,7 @@ enum regex_type {
MATCH_MIDDLE_ONLY,
MATCH_END_ONLY,
MATCH_GLOB,
MATCH_INDEX,
};

struct regex {
Expand Down
5 changes: 5 additions & 0 deletions kernel/trace/trace_events_filter.c
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down Expand Up @@ -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;
Expand Down

0 comments on commit f79b3f3

Please sign in to comment.