From a6fb6012ed4ec0450389693421a954a4c3740bec Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (VMware)" Date: Thu, 22 Mar 2018 19:28:54 -0400 Subject: init: Fix initcall0 name as it is "pure" not "early" The early_initcall() functions get assigned to __initcall_start[]. These are called by do_pre_smp_initcalls(). The initcall_levels[] array starts with __initcall0_start[], and initcall_levels[] are to match the initcall_level_names[] array. The first name in that array is "early", but that is not correct. As pure_initcall() functions get assigned to __initcall0_start[] array. Change the first name in initcall_level_names[] array to "pure". Signed-off-by: Steven Rostedt (VMware) --- init/main.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'init') diff --git a/init/main.c b/init/main.c index 969eaf140ef0..0ebdd5f15be8 100644 --- a/init/main.c +++ b/init/main.c @@ -874,7 +874,7 @@ static initcall_t *initcall_levels[] __initdata = { /* Keep these in sync with initcalls in include/linux/init.h */ static char *initcall_level_names[] __initdata = { - "early", + "pure", "core", "postcore", "arch", -- cgit v1.2.1 From 4ee7c60de83ac01fa4c33c55937357601631e8ad Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (VMware)" Date: Fri, 23 Mar 2018 10:18:03 -0400 Subject: init, tracing: Add initcall trace events Being able to trace the start and stop of initcalls is useful to see where the timings are an issue. There is already an "initcall_debug" parameter, but that can cause a large overhead itself, as the printing of the information may take longer than the initcall functions. Adding in a start and finish trace event around the initcall functions, as well as a trace event that records the level of the initcalls, one can get a much finer measurement of the times and interactions of the initcalls themselves, as trace events are much lighter than printk()s. Suggested-by: Abderrahmane Benbachir Signed-off-by: Steven Rostedt (VMware) --- init/main.c | 7 +++++++ 1 file changed, 7 insertions(+) (limited to 'init') diff --git a/init/main.c b/init/main.c index 0ebdd5f15be8..2af8f2bb5ca8 100644 --- a/init/main.c +++ b/init/main.c @@ -97,6 +97,9 @@ #include #include +#define CREATE_TRACE_POINTS +#include + static int kernel_init(void *); extern void init_IRQ(void); @@ -827,10 +830,12 @@ int __init_or_module do_one_initcall(initcall_t fn) if (initcall_blacklisted(fn)) return -EPERM; + trace_initcall_start(fn); if (initcall_debug) ret = do_one_initcall_debug(fn); else ret = fn(); + trace_initcall_finish(fn, ret); msgbuf[0] = 0; @@ -895,6 +900,7 @@ static void __init do_initcall_level(int level) level, level, NULL, &repair_env_string); + trace_initcall_level(initcall_level_names[level]); for (fn = initcall_levels[level]; fn < initcall_levels[level+1]; fn++) do_one_initcall(*fn); } @@ -929,6 +935,7 @@ static void __init do_pre_smp_initcalls(void) { initcall_t *fn; + trace_initcall_level("early"); for (fn = __initcall_start; fn < __initcall0_start; fn++) do_one_initcall(*fn); } -- cgit v1.2.1 From 4e37958d1288ce90e8b8eb526ed93d6b2ee6cf54 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (VMware)" Date: Mon, 26 Mar 2018 13:31:07 -0400 Subject: init, tracing: Have printk come through the trace events for initcall_debug With trace events set before and after the initcall function calls, instead of having a separate routine for printing out the initcalls when initcall_debug is specified on the kernel command line, have the code register a callback to the tracepoints where the initcall trace events are. This removes the need for having a separate function to do the initcalls as the tracepoint callbacks can handle the printk. It also includes other initcalls that are not called by the do_one_initcall() which includes console and security initcalls. Signed-off-by: Steven Rostedt (VMware) --- init/main.c | 51 +++++++++++++++++++++++++++++++++++---------------- 1 file changed, 35 insertions(+), 16 deletions(-) (limited to 'init') diff --git a/init/main.c b/init/main.c index 2af8f2bb5ca8..589d1226016e 100644 --- a/init/main.c +++ b/init/main.c @@ -494,6 +494,10 @@ void __init __weak thread_stack_cache_init(void) void __init __weak mem_encrypt_init(void) { } +bool initcall_debug; +core_param(initcall_debug, initcall_debug, bool, 0644); +static void __init initcall_debug_enable(void); + /* * Set up kernel memory allocators */ @@ -615,6 +619,9 @@ asmlinkage __visible void __init start_kernel(void) /* Trace events are available after this */ trace_init(); + if (initcall_debug) + initcall_debug_enable(); + context_tracking_init(); /* init some links before init_ISA_irqs() */ early_irq_init(); @@ -731,9 +738,6 @@ static void __init do_ctors(void) #endif } -bool initcall_debug; -core_param(initcall_debug, initcall_debug, bool, 0644); - #ifdef CONFIG_KALLSYMS struct blacklist_entry { struct list_head next; @@ -803,38 +807,53 @@ static bool __init_or_module initcall_blacklisted(initcall_t fn) #endif __setup("initcall_blacklist=", initcall_blacklist); -static int __init_or_module do_one_initcall_debug(initcall_t fn) +static __init_or_module void +trace_initcall_start_cb(void *data, initcall_t fn) { - ktime_t calltime, delta, rettime; - unsigned long long duration; - int ret; + ktime_t *calltime = (ktime_t *)data; printk(KERN_DEBUG "calling %pF @ %i\n", fn, task_pid_nr(current)); - calltime = ktime_get(); - ret = fn(); + *calltime = ktime_get(); +} + +static __init_or_module void +trace_initcall_finish_cb(void *data, initcall_t fn, int ret) +{ + ktime_t *calltime = (ktime_t *)data; + ktime_t delta, rettime; + unsigned long long duration; + rettime = ktime_get(); - delta = ktime_sub(rettime, calltime); + delta = ktime_sub(rettime, *calltime); duration = (unsigned long long) ktime_to_ns(delta) >> 10; printk(KERN_DEBUG "initcall %pF returned %d after %lld usecs\n", fn, ret, duration); +} - return ret; +static ktime_t initcall_calltime; + +static void __init initcall_debug_enable(void) +{ + int ret; + + ret = register_trace_initcall_start(trace_initcall_start_cb, + &initcall_calltime); + ret |= register_trace_initcall_finish(trace_initcall_finish_cb, + &initcall_calltime); + WARN(ret, "Failed to register initcall tracepoints\n"); } int __init_or_module do_one_initcall(initcall_t fn) { int count = preempt_count(); - int ret; char msgbuf[64]; + int ret; if (initcall_blacklisted(fn)) return -EPERM; trace_initcall_start(fn); - if (initcall_debug) - ret = do_one_initcall_debug(fn); - else - ret = fn(); + ret = fn(); trace_initcall_finish(fn, ret); msgbuf[0] = 0; -- cgit v1.2.1 From b0dc52f15e7fe2b973ecfe4f3706f1b35ce3943a Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (VMware)" Date: Fri, 6 Apr 2018 09:24:25 -0400 Subject: init: Have initcall_debug still work without CONFIG_TRACEPOINTS Add macros around the initcall_debug tracepoint code to have the code to default back to the old method if CONFIG_TRACEPOINTS is not enabled. Signed-off-by: Steven Rostedt (VMware) --- init/main.c | 28 ++++++++++++++++++++++++++-- 1 file changed, 26 insertions(+), 2 deletions(-) (limited to 'init') diff --git a/init/main.c b/init/main.c index 589d1226016e..6f6e6fc6f4b9 100644 --- a/init/main.c +++ b/init/main.c @@ -496,7 +496,14 @@ void __init __weak mem_encrypt_init(void) { } bool initcall_debug; core_param(initcall_debug, initcall_debug, bool, 0644); + +#ifdef TRACEPOINTS_ENABLED static void __init initcall_debug_enable(void); +#else +static inline void initcall_debug_enable(void) +{ +} +#endif /* * Set up kernel memory allocators @@ -832,6 +839,7 @@ trace_initcall_finish_cb(void *data, initcall_t fn, int ret) static ktime_t initcall_calltime; +#ifdef TRACEPOINTS_ENABLED static void __init initcall_debug_enable(void) { int ret; @@ -842,6 +850,22 @@ static void __init initcall_debug_enable(void) &initcall_calltime); WARN(ret, "Failed to register initcall tracepoints\n"); } +# define do_trace_initcall_start trace_initcall_start +# define do_trace_initcall_finish trace_initcall_finish +#else +static inline void do_trace_initcall_start(initcall_t fn) +{ + if (!initcall_debug) + return; + trace_initcall_start_cb(&initcall_calltime, fn); +} +static inline void do_trace_initcall_finish(initcall_t fn, int ret) +{ + if (!initcall_debug) + return; + trace_initcall_finish_cb(&initcall_calltime, fn, ret); +} +#endif /* !TRACEPOINTS_ENABLED */ int __init_or_module do_one_initcall(initcall_t fn) { @@ -852,9 +876,9 @@ int __init_or_module do_one_initcall(initcall_t fn) if (initcall_blacklisted(fn)) return -EPERM; - trace_initcall_start(fn); + do_trace_initcall_start(fn); ret = fn(); - trace_initcall_finish(fn, ret); + do_trace_initcall_finish(fn, ret); msgbuf[0] = 0; -- cgit v1.2.1