ftrace: Show timings of how long nop patching took

Since the beginning of ftrace, the code that did the patching had its
timings saved on how long it took to complete. But this information was
never exposed. It was used for debugging and exposing it was always
something that was on the TODO list. Now it's time to expose it. There's
even a file that is where it should go!

Also include how long patching modules took as a separate value.

 # cat /sys/kernel/tracing/dyn_ftrace_total_info
 57680 pages:231 groups: 9
 ftrace boot update time = 14024666 (ns)
 ftrace module total update time = 126070 (ns)

Cc: Masami Hiramatsu <[email protected]>
Cc: Mark Rutland <[email protected]>
Cc: Mathieu Desnoyers <[email protected]>
Cc: Mike Rapoport <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: https://lore.kernel.org/[email protected]
Signed-off-by: Steven Rostedt (Google) <[email protected]>

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index b4ef469f4fd207f94713baadeb6f5f3da329679b..71e53eaba8bc66e972b8be1511654a3d700beeab 100644 (file)
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -3686,7 +3686,8 @@ static int ftrace_hash_move_and_update_subops(struct ftrace_ops *subops,
 }
 
 
-static u64             ftrace_update_time;
+u64                    ftrace_update_time;
+u64                    ftrace_total_mod_time;
 unsigned long          ftrace_update_tot_cnt;
 unsigned long          ftrace_number_of_pages;
 unsigned long          ftrace_number_of_groups;
@@ -3706,7 +3707,7 @@ static int ftrace_update_code(struct module *mod, struct ftrace_page *new_pgs)
        bool init_nop = ftrace_need_init_nop();
        struct ftrace_page *pg;
        struct dyn_ftrace *p;
-       u64 start, stop;
+       u64 start, stop, update_time;
        unsigned long update_cnt = 0;
        unsigned long rec_flags = 0;
        int i;
@@ -3750,7 +3751,11 @@ static int ftrace_update_code(struct module *mod, struct ftrace_page *new_pgs)
        }
 
        stop = ftrace_now(raw_smp_processor_id());
-       ftrace_update_time = stop - start;
+       update_time = stop - start;
+       if (mod)
+               ftrace_total_mod_time += update_time;
+       else
+               ftrace_update_time = update_time;
        ftrace_update_tot_cnt += update_cnt;
 
        return 0;

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index c01375adc4714a563c71dc0aeeb2b30c78cc9478..405dcf49815991888c851e3247709239808cdfd9 100644 (file)
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -8548,15 +8548,22 @@ tracing_read_dyn_info(struct file *filp, char __user *ubuf,
        char *buf;
        int r;
 
-       /* 256 should be plenty to hold the amount needed */
-       buf = kmalloc(256, GFP_KERNEL);
+       /* 512 should be plenty to hold the amount needed */
+#define DYN_INFO_BUF_SIZE      512
+
+       buf = kmalloc(DYN_INFO_BUF_SIZE, GFP_KERNEL);
        if (!buf)
                return -ENOMEM;
 
-       r = scnprintf(buf, 256, "%ld pages:%ld groups: %ld\n",
+       r = scnprintf(buf, DYN_INFO_BUF_SIZE,
+                     "%ld pages:%ld groups: %ld\n"
+                     "ftrace boot update time = %llu (ns)\n"
+                     "ftrace module total update time = %llu (ns)\n",
                      ftrace_update_tot_cnt,
                      ftrace_number_of_pages,
-                     ftrace_number_of_groups);
+                     ftrace_number_of_groups,
+                     ftrace_update_time,
+                     ftrace_total_mod_time);
 
        ret = simple_read_from_buffer(ubuf, cnt, ppos, buf, r);
        kfree(buf);

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 6adf48ef4312fcabd0dfdbcd740bfc2e6b82f962..3307dad4d917629a3853d434280e13a189eae586 100644 (file)
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -775,6 +775,8 @@ extern void trace_event_follow_fork(struct trace_array *tr, bool enable);
 extern unsigned long ftrace_update_tot_cnt;
 extern unsigned long ftrace_number_of_pages;
 extern unsigned long ftrace_number_of_groups;
+extern u64 ftrace_update_time;
+extern u64 ftrace_total_mod_time;
 void ftrace_init_trace_array(struct trace_array *tr);
 #else
 static inline void ftrace_init_trace_array(struct trace_array *tr) { }