tracing: Allow function tracing to start earlier in boot up
Subsystems (4)
Steven Rostedt
maintainercover tracing: Allow function tracing to start earlier in boot up
I've had people ask about moving tracing up further in the boot process. This patch series looks at function tracing only. It allows for tracing (and function filtering) to be moved right after memory is initialized. To have it happen before memory initialization would require a bit more work with allocating the ring buffer. But this is a start.
I placed a hook into free_reserved_area() which is used by all archs to free the init memory. Having it pass the range being freed to ftrace lets ftrace clean up any function that is registered such that it doesn't try to modify code that no longer exists.
Steven Rostedt (VMware) (4):
tracing: Split tracing initialization into two for early initialization
ftrace: Move ftrace_init() to right after memory initialization
ftrace: Have function tracing start in early boot up
ftrace: Allow for function tracing to record init functions on boot up
----
include/linux/ftrace.h | 5 +++++ include/linux/init.h | 4 +++- init/main.c | 9 ++++++--- kernel/trace/ftrace.c | 44 ++++++++++++++++++++++++++++++++++++++++++ kernel/trace/trace.c | 9 ++++++++- kernel/trace/trace.h | 2 ++ kernel/trace/trace_functions.c | 3 +-- mm/page_alloc.c | 4 ++++ scripts/recordmcount.c | 1 + scripts/recordmcount.pl | 1 + 10 files changed, 75 insertions(+), 7 deletions(-)
Steven Rostedt
maintainerRFC PATCH 1/4 tracing: Split tracing initialization into two for early initialization
From: "Steven Rostedt (VMware)" <[email protected]>
Create an early_trace_init() function that will initialize the buffers and allow for ealier use of trace_printk(). This will also allow for future work to have function tracing start earlier at boot up.
--- include/linux/ftrace.h | 2 ++ init/main.c | 5 ++++- kernel/trace/trace.c | 6 +++++- 3 files changed, 11 insertions(+), 2 deletions(-)
include/linux/ftrace.h +2 -0
@@ -42,8 +42,10 @@/* Main tracing buffer and events set up */ #ifdef CONFIG_TRACING void trace_init (void ); +void early_trace_init (void );#else static inline void trace_init (void ) { } +static inline void early_trace_init (void ) { }#endif struct module ;
init/main.c +4 -1
@@ -539,6 +539,9 @@ asmlinkage __visible void __init start_kernel(void)trap_init ();mm_init (); +/* trace_printk can be enabled here */ +early_trace_init (); +/* * Set up the scheduler prior starting any interrupts (such as the * timer interrupt). Full topology setup happens at smp_init()
@@ -564,7 +567,7 @@ asmlinkage __visible void __init start_kernel(void)rcu_init (); -/* trace_printk() and trace points may be used after this */ +/* Trace events are available after this */ trace_init ();context_tracking_init ();
kernel/trace/trace.c +5 -1
@@ -7999,7 +7999,7 @@ __init static int tracer_alloc_buffers(void)return ret; } -void __init trace_init (void ) +void __init early_trace_init (void ) {if (tracepoint_printk) { tracepoint_print_iter =
@@ -8010,6 +8010,10 @@ void __init trace_init(void)static_key_enable (&tracepoint_printk_key.key); }tracer_alloc_buffers (); +} + +void __init trace_init (void ) +{trace_event_init (); }
Signature · 1 line
2.10.2
Steven Rostedt
maintainerRFC PATCH 2/4 ftrace: Move ftrace_init() to right after memory initialization
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
Initialize the ftrace records immediately after memory initialization, as that is all that is required for the records to be created. This will allow for future work to get function tracing started earlier in the boot process.
--- init/main.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
init/main.c +2 -2
@@ -539,6 +539,8 @@ asmlinkage __visible void __init start_kernel(void)trap_init ();mm_init (); +ftrace_init (); +/* trace_printk can be enabled here */ early_trace_init ();
@@ -670,8 +672,6 @@ asmlinkage __visible void __init start_kernel(void)efi_free_boot_services (); } -ftrace_init (); -/* Do the rest non-__init'ed, we're now alive */ rest_init (); }
Signature · 1 line
2.10.2
Steven Rostedt
maintainerRFC PATCH 3/4 ftrace: Have function tracing start in early boot up
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
Register the function tracer right after the tracing buffers are initialized in early boot up. This will allow function tracing to begin early if it is enabled via the kernel command line.
--- kernel/trace/trace.c | 3 +++ kernel/trace/trace.h | 2 ++ kernel/trace/trace_functions.c | 3 +-- 3 files changed, 6 insertions(+), 2 deletions(-)
kernel/trace/trace.c +3 -0
@@ -7965,6 +7965,9 @@ __init static int tracer_alloc_buffers(void)register_tracer (&nop_trace); +/* Function tracing may start here (via kernel command line) */ +init_function_trace (); +/* All seems OK, enable tracing */ tracing_disabled =0 ;
kernel/trace/trace.h +2 -0
@@ -896,6 +896,7 @@ int using_ftrace_ops_list_func(void);void ftrace_init_tracefs (struct trace_array *tr,struct dentry *d_tracer);void ftrace_init_tracefs_toplevel (struct trace_array *tr,struct dentry *d_tracer); +int init_function_trace (void );#else static inline int ftrace_trace_task (struct trace_array *tr) {
@@ -914,6 +915,7 @@ ftrace_init_global_array_ops(struct trace_array *tr) { }static inline void ftrace_reset_array_ops (struct trace_array *tr) { }static inline void ftrace_init_tracefs (struct trace_array *tr,struct dentry *d) { }static inline void ftrace_init_tracefs_toplevel (struct trace_array *tr,struct dentry *d) { } +static inline int init_function_trace (void ) { }/* ftace_func_t type is not defined, use macro instead of static inline */ #define ftrace_init_array_ops (tr, func) do { } while (0)#endif /* CONFIG_FUNCTION_TRACER */
kernel/trace/trace_functions.c +1 -2
@@ -687,9 +687,8 @@ static inline int init_func_cmd_traceon(void) }#endif /* CONFIG_DYNAMIC_FTRACE */ -static __init int init_function_trace (void ) +__init int init_function_trace (void ) {init_func_cmd_traceon ();return register_tracer (&function_trace); } -core_initcall (init_function_trace);
Signature · 1 line
2.10.2
Steven Rostedt
maintainerRFC PATCH 4/4 ftrace: Allow for function tracing to record init functions on boot up
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
Adding a hook into free_reserve_area() that informs ftrace that boot up init text is being free, lets ftrace safely remove those init functions from its records, which keeps ftrace from trying to modify text that no longer exists.
Note, this still does not allow for tracing .init text of modules, as modules require different work for freeing its init code.
--- include/linux/ftrace.h | 3 +++ include/linux/init.h | 4 +++- kernel/trace/ftrace.c | 44 ++++++++++++++++++++++++++++++++++++++++++++ mm/page_alloc.c | 4 ++++ scripts/recordmcount.c | 1 + scripts/recordmcount.pl | 1 + 6 files changed, 56 insertions(+), 1 deletion(-)
include/linux/ftrace.h +3 -0
@@ -249,6 +249,8 @@ static inline int ftrace_function_local_disabled(struct ftrace_ops *ops)extern void ftrace_stub (unsigned long a0,unsigned long a1,struct ftrace_ops *op,struct pt_regs *regs); +void ftrace_free_mem (void *start,void *end); +#else /* !CONFIG_FUNCTION_TRACER */ /* * (un)register_ftrace_function must be a macro since the ops parameter
@@ -262,6 +264,7 @@ static inline int ftrace_nr_registered_ops(void) }static inline void clear_ftrace_function (void ) { }static inline void ftrace_kill (void ) { } +static inline void ftrace_free_mem (void *start,void *end) { }#endif /* CONFIG_FUNCTION_TRACER */ #ifdef CONFIG_STACK_TRACER
include/linux/init.h +3 -1
@@ -39,7 +39,7 @@/* These are for everybody (although not all archs will actually discard it in modules) */ -#define __init __section(.init.text) __cold notrace __latent_entropy +#define __init __section(.init.text) __cold __inittrace __latent_entropy#define __initdata __section(.init.data)#define __initconst __section(.init.rodata)#define __exitdata __section(.exit.data)
@@ -68,8 +68,10 @@#ifdef MODULE #define __exitused +#define __inittrace notrace#else #define __exitused __used +#define __inittrace#endif #define __exit __section(.exit.text) __exitused __cold notrace
kernel/trace/ftrace.c +44 -0
50 lines not on this page · raw message
mm/page_alloc.c +4 -0
@@ -64,6 +64,7 @@#include <linux/page_owner.h> #include <linux/kthread.h> #include <linux/memcontrol.h> +#include <linux/ftrace.h> #include <asm/sections.h> #include <asm/tlbflush.h>
@@ -6441,6 +6442,9 @@ unsigned long free_reserved_area(void *start, void *end, int poison, char *s)void *pos;unsigned long pages =0 ; +/* This may be .init text, inform ftrace to remove it */ +ftrace_free_mem (start, end); + start = (void *)PAGE_ALIGN ((unsigned long )start); end = (void *)((unsigned long )end &PAGE_MASK );for (pos = start; pos < end; pos +=PAGE_SIZE , pages++) {
scripts/recordmcount.c +1 -0
@@ -412,6 +412,7 @@ static int is_mcounted_section_name(char const *const txtname) {return strcmp (".text" , txtname) ==0 || +strcmp (".init.text" , txtname) ==0 ||strcmp (".ref.text" , txtname) ==0 ||strcmp (".sched.text" , txtname) ==0 || strcmp(".spinlock.text", txtname) == 0 ||
scripts/recordmcount.pl +1 -0
@@ -130,6 +130,7 @@ if ($inputfile =~ m,kernel/trace/ftrace\.o$,) { # Acceptable sections to record. my %text_sections = ( ".text" => 1, + ".init.text" => 1, ".ref.text" => 1, ".sched.text" => 1, ".spinlock.text" => 1,
Signature · 8 lines
2.10.2 -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Steven Rostedt
maintainerRe: [RFC][PATCH 4/4] ftrace: Allow for function tracing to record init functions on boot up
Dear mm folks,
Are you OK with this change? I need a hook to when the init sections are being freed along with the address that are being freed. As each arch frees their own init sections I need a single location to place my hook. The archs all call free_reserved_area(). As this isn't a critical section (ie. one that needs to be really fast), calling into ftrace with the freed address should not be an issue. The ftrace code uses a binary search within the blocks of locations so it is rather fast itself.
Thoughts? Acks? :-)
-- Steve
Quoted 13 lines
mm/page_alloc.c +1
-0@@ -64,6 +64,7 @@#include <linux/page_owner.h> #include <linux/kthread.h> #include <linux/memcontrol.h> +#include <linux/ftrace.h> #include <asm/sections.h> #include <asm/tlbflush.h>
mm/page_alloc.c unsigned long free_reserved_area(void *start, void *end, int poison, char *s) · line 6450
Quoted 9 lines
mm/page_alloc.c +3
-0@@ -6441,6 +6442,9 @@ unsigned long free_reserved_area(void *start, void *end, int poison, char *s)void *pos;unsigned long pages =0 ; +/* This may be .init text, inform ftrace to remove it */ +ftrace_free_mem (start, end); + start = (void *)PAGE_ALIGN ((unsigned long )start); end = (void *)((unsigned long )end &PAGE_MASK );for (pos = start; pos < end; pos +=PAGE_SIZE , pages++) {
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 5 lines · Steven Rostedt
I've had people ask about moving tracing up further in the boot process. This patch series looks at function tracing only. It allows for tracing (and function filtering) to be moved right after memory is initialized. To have it happen before memory initialization would require a bit more work with allocating the ring buffer. But this is a start.
I just tested out the patch and it does move function trace up to about 100ms from boot which is nice. What I'd really like is for graph trace to start sooner as well.
P.S. I've noticed that the dmesg log and ftrace log times don't seem to match up anymore since the v10.0 release. Is the default still the local clock? On v10.0-rc8 I was able to match initcall_debug output with do_one_initcall function_graph trace perfectly. But the latest is off by anywhere from several microseconds to several milliseconds. Did I just get lucky with v10.0-rc8 or should these still align?
v10.0-rc8 (ftrace time = dmesg time)
FTRACE:
0.519902 | 0) systemd-1 | | do_one_initcall() {
0.519921 | 0) systemd-1 | | do_one_initcall() {
0.519929 | 0) systemd-1 | | do_one_initcall() {
0.519938 | 0) systemd-1 | | do_one_initcall() {
0.519946 | 0) systemd-1 | | do_one_initcall() {
DMESG:
[ 0.519909] calling init_per_zone_wmark_min+0x0/0x73 @ 1
[ 0.519925] calling init_zero_pfn+0x0/0x3d @ 1
[ 0.519932] calling memory_failure_init+0x0/0xa4 @ 1
[ 0.519941] calling cma_init_reserved_areas+0x0/0x1cd @ 1
[ 0.519949] calling fsnotify_init+0x0/0x26 @ 1v4.11-rc1 (ftrace = dmesg + 5.089 ms)
FTRACE:
0.445317 | 2) systemd-1 | | do_one_initcall() {
0.445338 | 2) systemd-1 | | do_one_initcall() {
0.445346 | 2) systemd-1 | | do_one_initcall() {
0.445355 | 2) systemd-1 | | do_one_initcall() {
0.445363 | 2) systemd-1 | | do_one_initcall() {
DMESG:
[ 0.440232] calling init_per_zone_wmark_min+0x0/0x73 @ 1
[ 0.440249] calling init_zero_pfn+0x0/0x3d @ 1
[ 0.440257] calling memory_failure_init+0x0/0xa4 @ 1
[ 0.440266] calling cma_init_reserved_areas+0x0/0x1cd @ 1
[ 0.440275] calling fsnotify_init+0x0/0x26 @ 1Quoted 25 lines
I placed a hook into
free_reserved_area()which is used by all archs to free the init memory. Having it pass the range being freed to ftrace lets ftrace clean up any function that is registered such that it doesn't try to modify code that no longer exists.Steven Rostedt (VMware) (4):
tracing: Split tracing initialization into two for early initialization
ftrace: Moveftrace_init()to right after memory initialization
ftrace: Have function tracing start in early boot up
ftrace: Allow for function tracing to record init functions on boot up----
include/linux/ftrace.h | 5 +++++ include/linux/init.h | 4 +++- init/main.c | 9 ++++++--- kernel/trace/ftrace.c | 44 ++++++++++++++++++++++++++++++++++++++++++ kernel/trace/trace.c | 9 ++++++++- kernel/trace/trace.h | 2 ++ kernel/trace/trace_functions.c | 3 +-- mm/page_alloc.c | 4 ++++ scripts/recordmcount.c | 1 + scripts/recordmcount.pl | 1 + 10 files changed, 75 insertions(+), 7 deletions(-)
Quoted 36 lines · Todd Brandt
Quoted 5 lines · Steven Rostedt
I've had people ask about moving tracing up further in the boot process. This patch series looks at function tracing only. It allows for tracing (and function filtering) to be moved right after memory is initialized. To have it happen before memory initialization would require a bit more work with allocating the ring buffer. But this is a start.
I just tested out the patch and it does move function trace up to about 100ms from boot which is nice. What I'd really like is for graph trace to start sooner as well.
P.S. I've noticed that the dmesg log and ftrace log times don't seem to match up anymore since the v10.0 release. Is the default still the local clock? On v10.0-rc8 I was able to matchinitcall_debugoutput withdo_one_initcallfunction_graphtrace perfectly. But the latest is off by anywhere from several microseconds to several milliseconds. Did I just get lucky with v10.0-rc8 or should these still align?v10.0-rc8 (ftrace time = dmesg time)
FTRACE:
0.519902 | 0) systemd-1 | | do_one_initcall() { 0.519921 | 0) systemd-1 | | do_one_initcall() { 0.519929 | 0) systemd-1 | | do_one_initcall() { 0.519938 | 0) systemd-1 | | do_one_initcall() { 0.519946 | 0) systemd-1 | | do_one_initcall() { DMESG: [ 0.519909] calling init_per_zone_wmark_min+0x0/0x73 @ 1 [ 0.519925] calling init_zero_pfn+0x0/0x3d @ 1 [ 0.519932] calling memory_failure_init+0x0/0xa4 @ 1 [ 0.519941] calling cma_init_reserved_areas+0x0/0x1cd @ 1 [ 0.519949] calling fsnotify_init+0x0/0x26 @ 1v4.11-rc1 (ftrace = dmesg + 5.089 ms)
FTRACE:
Quoted 11 lines
0.445317 | 2) systemd-1 | | do_one_initcall() {
0.445338 | 2) systemd-1 | | do_one_initcall() {
0.445346 | 2) systemd-1 | | do_one_initcall() {
0.445355 | 2) systemd-1 | | do_one_initcall() {
0.445363 | 2) systemd-1 | | do_one_initcall() {
DMESG:
[ 0.440232] calling init_per_zone_wmark_min+0x0/0x73 @ 1
[ 0.440249] calling init_zero_pfn+0x0/0x3d @ 1
[ 0.440257] calling memory_failure_init+0x0/0xa4 @ 1
[ 0.440266] calling cma_init_reserved_areas+0x0/0x1cd @ 1
[ 0.440275] calling fsnotify_init+0x0/0x26 @ 1Oops, no sooner than 5 minutes after I sent this did I figure out there's a trace_clock kernel parameter (not in kernel-parameters.txt). Once I set it to global all is well. Never mind :)
Quoted 28 lines
Quoted 27 lines
I placed a hook into
free_reserved_area()which is used by all archs to free the init memory. Having it pass the range being freed to ftrace lets ftrace clean up any function that is registered such that it doesn't try to modify code that no longer exists.Steven Rostedt (VMware) (4):
tracing: Split tracing initialization into two for early initialization
ftrace: Moveftrace_init()to right after memory initialization
ftrace: Have function tracing start in early boot up
ftrace: Allow for function tracing to record init functions on boot up----
include/linux/ftrace.h | 5 +++++ include/linux/init.h | 4 +++- init/main.c | 9 ++++++--- kernel/trace/ftrace.c | 44 ++++++++++++++++++++++++++++++++++++++++++ kernel/trace/trace.c | 9 ++++++++- kernel/trace/trace.h | 2 ++ kernel/trace/trace_functions.c | 3 +-- mm/page_alloc.c | 4 ++++ scripts/recordmcount.c | 1 + scripts/recordmcount.pl | 1 + 10 files changed, 75 insertions(+), 7 deletions(-)
Steven Rostedt
maintainerQuoted 11 lines · On Wed, 08 Mar 2017 11:32:25 -0800 Todd Brandt <[email protected]>…
Quoted 10 lines · Todd Brandt
Quoted 5 lines · Steven Rostedt
I've had people ask about moving tracing up further in the boot process. This patch series looks at function tracing only. It allows for tracing (and function filtering) to be moved right after memory is initialized. To have it happen before memory initialization would require a bit more work with allocating the ring buffer. But this is a start.
I just tested out the patch and it does move function trace up to about 100ms from boot which is nice. What I'd really like is for graph trace to start sooner as well.
I can add this. I just wanted this out first.
The one part I want people to notice is the last patch where I add a hook into the free mem reserve. I'll ping the mm folks to make sure they are OK with that.
Quoted 9 lines
Quoted 5 lines
[ 0.440232] calling init_per_zone_wmark_min+0x0/0x73 @ 1 [ 0.440249] calling init_zero_pfn+0x0/0x3d @ 1 [ 0.440257] calling memory_failure_init+0x0/0xa4 @ 1 [ 0.440266] calling cma_init_reserved_areas+0x0/0x1cd @ 1 [ 0.440275] calling fsnotify_init+0x0/0x26 @ 1Oops, no sooner than 5 minutes after I sent this did I figure out there's a
trace_clockkernel parameter (not in kernel-parameters.txt). Once I set it to global all is well. Never mind :)
I was just about to ask ;-)
-- Steve