Peter, Andrew,
This keeps initcall_debug printing printk()s, but adds the feature of
those locations also being trace events. Are you OK if I add this?
Works with and without TRACEPOINTS enabled.
-- Steve
On Fri, 06 Apr 2018 15:08:54 -0400
Steven Rostedt <rost...@goodmis.org> wrote:
> A while ago we had a boot tracer. But it was eventually removed:
> commit 30dbb20e68e6f ("tracing: Remove boot tracer").
>
> The rationale was because there is already a initcall_debug boot option
> that causes printk()s of all the initcall functions.
>
> The problem with the initcall_debug option is that printk() is awfully slow,
> and makes it difficult to see the real impact of initcalls. Mainly because
> a single printk() is usually slower than most initcall functions.
> Yes the timings are done within the printks, but it slows down the
> boot up tremendously. Tracing can do the same without needing to
> slow down boot up.
>
> Instead of bringing back the boot tracer, adding trace events around the
> initcall functions, and even one to denote which level the initcall
> functions are being called from, adds the necessary information to
> analyze the initcalls without the high overhead of printk()s, that
> can substantially slow down the boot process.
>
> Another positive, is that the console initcall functions themselves
> can also be traced. The timestamps are not operational at that time
> but you can see which consoles are being registered. I saw this on
> one of my test boxes:
>
> <idle>-0 [000] ...1 0.000000: initcall_level: level=console
> <idle>-0 [000] ...1 0.000000: initcall_start: func=con_init+0x0/0x224
> <idle>-0 [000] ...1 0.000000: initcall_finish:
> func=con_init+0x0/0x224 ret=0
> <idle>-0 [000] ...1 0.000000: initcall_start:
> func=hvc_console_init+0x0/0x19
> <idle>-0 [000] ...1 0.000000: initcall_finish:
> func=hvc_console_init+0x0/0x19 ret=0
> <idle>-0 [000] ...1 0.000000: initcall_start:
> func=xen_cons_init+0x0/0x60
> <idle>-0 [000] ...1 0.000000: initcall_finish:
> func=xen_cons_init+0x0/0x60 ret=0
> <idle>-0 [000] ...1 0.000000: initcall_start:
> func=univ8250_console_init+0x0/0x2d
> <idle>-0 [000] ...1 0.000000: initcall_finish:
> func=univ8250_console_init+0x0/0x2d ret=0
>
> I didn't even realize that I had some of those consoles configured.
>
> Anyone have any issues with me adding this?
>
> git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> ftrace/core
>
> Head SHA1: 7af49b07cb525d36a916b841dc9329c187789e1f
>
>
> Abderrahmane Benbachir (1):
> init, tracing: instrument security and console initcall trace events
>
> Steven Rostedt (VMware) (3):
> init, tracing: Add initcall trace events
> init, tracing: Have printk come through the trace events for
> initcall_debug
> init: Have initcall_debug still work without CONFIG_TRACEPOINTS
>
> ----
> Changes since v1:
>
> Added the last patch that makes initcall_debug work even when
> TRACEPOINTS is not configured. It just goes back to the old
> method (with if statements, instead of hooking into trace_events).
>
> include/trace/events/initcall.h | 66 ++++++++++++++++++++++++++++++++++
> init/main.c | 78
> ++++++++++++++++++++++++++++++++---------
> kernel/printk/printk.c | 7 +++-
> security/security.c | 8 ++++-
> 4 files changed, 141 insertions(+), 18 deletions(-)
> create mode 100644 include/trace/events/initcall.h
