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

Signed-off-by: Yordan Karadzhov (VMware) <y.kar...@gmail.com>
---
 kernel/trace/trace.h         |  3 +++
 kernel/trace/trace_entries.h | 39 ++++++++++++++++++++++++++++++
 kernel/trace/trace_output.c  | 47 ++++++++++++++++++++++++++++++++++++
 3 files changed, 89 insertions(+)

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 5506424eae2a..6a5b4c2a0fa7 100644
--- 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 4547ac59da61..6f98c3b4e4fa 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -338,3 +338,42 @@ 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)                    
\
+
+#define FUNC_REPEATS_SET_DELTA_TS(entry, delta)                                
        \
+       do {                                                                    
\
+               if (likely(!((u64)delta >> 32))) {                              
\
+                       entry->bottom_delta_ts = delta;                         
\
+                       entry->top_delta_ts = 0;                                
\
+               } else {                                                        
\
+                       if (likely(!((u64)delta >> 48))) {                      
\
+                               entry->bottom_delta_ts = delta & U32_MAX;       
\
+                               entry->top_delta_ts = (delta >> 32);            
\
+                       } else {                                                
\
+                               /* Timestamp overflow. Set to max. */           
\
+                               entry->bottom_delta_ts = U32_MAX;               
\
+                               entry->top_delta_ts = U16_MAX;                  
\
+                       }                                                       
\
+               }                                                               
\
+       } while (0);                                                            
\
+
+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_ts: -%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 a0146e1fffdf..55b08e146afc 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1373,6 +1373,52 @@ 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, delta_ts: -%llu)\n",
+                        field->count,
+                        FUNC_REPEATS_GET_DELTA_TS(field));
+
+       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,
@@ -1385,6 +1431,7 @@ static struct trace_event *events[] __initdata = {
        &trace_print_event,
        &trace_hwlat_event,
        &trace_raw_data_event,
+       &trace_func_repeats_event,
        NULL
 };
 
-- 
2.25.1

Reply via email to