tracing: Define new ftrace event "func_repeats"

The event aims to consolidate the function tracing record in the cases
when a single function is called number of times consecutively.

	while (cond)
		do_func();

This may happen in various scenarios (busy waiting for example).
The new ftrace event can be used to show repeated function events with
a single event and save space on the ring buffer

Link: https://lkml.kernel.org/r/20210415181854.147448-3-y.karadz@gmail.com
Signed-off-by: Yordan Karadzhov (VMware) <y.karadz@gmail.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 5506424..6a5b4c2 100644 (file)
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -45,6 +45,7 @@ enum trace_type {
        TRACE_BPUTS,
        TRACE_HWLAT,
        TRACE_RAW_DATA,
+       TRACE_FUNC_REPEATS,
 
        __TRACE_LAST_TYPE,
 };
@@ -442,6 +443,8 @@ extern void __ftrace_bad_type(void);
                          TRACE_GRAPH_ENT);             \
                IF_ASSIGN(var, ent, struct ftrace_graph_ret_entry,      \
                          TRACE_GRAPH_RET);             \
+               IF_ASSIGN(var, ent, struct func_repeats_entry,          \
+                         TRACE_FUNC_REPEATS);                          \
                __ftrace_bad_type();                                    \
        } while (0)
 

diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index 4547ac5..251c819 100644 (file)
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -338,3 +338,25 @@ FTRACE_ENTRY(hwlat, hwlat_entry,
                 __entry->nmi_total_ts,
                 __entry->nmi_count)
 );
+
+#define FUNC_REPEATS_GET_DELTA_TS(entry)                               \
+       (((u64)(entry)->top_delta_ts << 32) | (entry)->bottom_delta_ts) \
+
+FTRACE_ENTRY(func_repeats, func_repeats_entry,
+
+       TRACE_FUNC_REPEATS,
+
+       F_STRUCT(
+               __field(        unsigned long,  ip              )
+               __field(        unsigned long,  parent_ip       )
+               __field(        u16     ,       count           )
+               __field(        u16     ,       top_delta_ts    )
+               __field(        u32     ,       bottom_delta_ts )
+       ),
+
+       F_printk(" %ps <-%ps\t(repeats:%u  delta: -%llu)",
+                (void *)__entry->ip,
+                (void *)__entry->parent_ip,
+                __entry->count,
+                FUNC_REPEATS_GET_DELTA_TS(__entry))
+);

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 333233d..3037f0c 100644 (file)
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1381,6 +1381,53 @@ static struct trace_event trace_raw_data_event = {
        .funcs          = &trace_raw_data_funcs,
 };
 
+static enum print_line_t
+trace_func_repeats_raw(struct trace_iterator *iter, int flags,
+                        struct trace_event *event)
+{
+       struct func_repeats_entry *field;
+       struct trace_seq *s = &iter->seq;
+
+       trace_assign_type(field, iter->ent);
+
+       trace_seq_printf(s, "%lu %lu %u %llu\n",
+                        field->ip,
+                        field->parent_ip,
+                        field->count,
+                        FUNC_REPEATS_GET_DELTA_TS(field));
+
+       return trace_handle_return(s);
+}
+
+static enum print_line_t
+trace_func_repeats_print(struct trace_iterator *iter, int flags,
+                        struct trace_event *event)
+{
+       struct func_repeats_entry *field;
+       struct trace_seq *s = &iter->seq;
+
+       trace_assign_type(field, iter->ent);
+
+       seq_print_ip_sym(s, field->ip, flags);
+       trace_seq_puts(s, " <-");
+       seq_print_ip_sym(s, field->parent_ip, flags);
+       trace_seq_printf(s, " (repeats: %u, last_ts:", field->count);
+       trace_print_time(s, iter,
+                        iter->ts - FUNC_REPEATS_GET_DELTA_TS(field));
+       trace_seq_puts(s, ")\n");
+
+       return trace_handle_return(s);
+}
+
+static struct trace_event_functions trace_func_repeats_funcs = {
+       .trace          = trace_func_repeats_print,
+       .raw            = trace_func_repeats_raw,
+};
+
+static struct trace_event trace_func_repeats_event = {
+       .type           = TRACE_FUNC_REPEATS,
+       .funcs          = &trace_func_repeats_funcs,
+};
 
 static struct trace_event *events[] __initdata = {
        &trace_fn_event,
@@ -1393,6 +1440,7 @@ static struct trace_event *events[] __initdata = {
        &trace_print_event,
        &trace_hwlat_event,
        &trace_raw_data_event,
+       &trace_func_repeats_event,
        NULL
 };