tracing: [4.12] Allow function tracing to start earlier in boot up
Subsystems (5)
Steven Rostedt
maintainercover tracing: [4.12] 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.
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
for-next
Head SHA1: 2b87965a1e6b6051435315d3f04627a5dbad979c
Steven Rostedt (VMware) (7):
tracing: Split tracing initialization into two for early initialization
ftrace: Move ftrace_init() to right after memory initialization
tracing: Postpone tracer start-up tests till the system is more robust
ftrace: Have function tracing start in early boot up
ftrace: Allow for function tracing to record init functions on boot up
tracing: Move trace_handle_return() out of line
ftrace/x86: Do no run CPU sync when there is only one CPU online
----
arch/x86/kernel/ftrace.c | 8 +++- include/linux/ftrace.h | 7 ++++ include/linux/init.h | 4 +- include/linux/trace_events.h | 11 +---- init/main.c | 9 +++-- kernel/trace/ftrace.c | 44 ++++++++++++++++++++ kernel/trace/trace.c | 92 +++++++++++++++++++++++++++++++++++++++++- kernel/trace/trace.h | 2 + kernel/trace/trace_functions.c | 3 +- mm/page_alloc.c | 4 ++ scripts/recordmcount.c | 1 + scripts/recordmcount.pl | 1 + 12 files changed, 168 insertions(+), 18 deletions(-)
Steven Rostedt
maintainerPATCH 1/7 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
@@ -545,6 +545,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()
@@ -570,7 +573,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
maintainerPATCH 2/7 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
@@ -545,6 +545,8 @@ asmlinkage __visible void __init start_kernel(void)trap_init ();mm_init (); +ftrace_init (); +/* trace_printk can be enabled here */ early_trace_init ();
@@ -673,8 +675,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
maintainerPATCH 3/7 tracing: Postpone tracer start-up tests till the system is more robust
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
As tracing can now be enabled very early in boot up, even before some critical system services (like scheduling), do not run the tracer selftests until after early_initcall() is performed. If a tracer is registered before such time, it is saved off in a list and the test is run when the system is able to handle more diverse functions.
--- kernel/trace/trace.c | 71 ++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 71 insertions(+)
kernel/trace/trace.c +71 -0
@@ -1424,6 +1424,28 @@ static int wait_on_pipe(struct trace_iterator *iter, bool full) }#ifdef CONFIG_FTRACE_STARTUP_TEST +static bool selftests_can_run; + +struct trace_selftests { +struct list_head list; +struct tracer *type; +}; + +static LIST_HEAD (postponed_selftests); + +static int save_selftest (struct tracer *type) +{ +struct trace_selftests *selftest; + + selftest =kmalloc (sizeof (*selftest),GFP_KERNEL ); +if (!selftest) +return -ENOMEM ; + + selftest->type = type; +list_add (&selftest->list, &postponed_selftests); +return 0 ; +} +static int run_tracer_selftest (struct tracer *type) {struct trace_array *tr = &global_trace;
@@ -1434,6 +1456,14 @@ static int run_tracer_selftest(struct tracer *type)return 0 ;/* +* If a tracer registers early in boot up (before scheduling is +* initialized and such), then do not run its selftests yet. +* Instead, run it a little later in the boot process. +*/ +if (!selftests_can_run) +return save_selftest (type); + +/* * Run a selftest on this tracer. * Here we reset the trace buffer, and set the current * tracer to be this tracer. The tracer can then run some
@@ -1482,6 +1512,47 @@ static int run_tracer_selftest(struct tracer *type)printk (KERN_CONT "PASSED\n" );return 0 ; } + +static __init int init_trace_selftests (void ) +{ +struct trace_selftests *p, *n; +struct tracer *t, **last; +int ret; + + selftests_can_run = true; + +mutex_lock (&trace_types_lock); + +if (list_empty (&postponed_selftests)) + goto out; + +pr_info ("Running postponed tracer tests:\n" ); + +list_for_each_entry_safe (p, n, &postponed_selftests, list) { + ret =run_tracer_selftest (p->type); +/* If the test fails, then warn and remove from available_tracers */ +if (ret <0 ) { +WARN (1 ,"tracer: %s failed selftest, disabling\n" , + p->type->name); + last = &trace_types; +for (t = trace_types; t; t = t->next) { +if (t == p->type) { + *last = t->next; +break ; + } + last = &t->next; + } + } +list_del (&p->list); +kfree (p); + } + + out: +mutex_unlock (&trace_types_lock); + +return 0 ; +} +early_initcall (init_trace_selftests);#else static inline int run_tracer_selftest (struct tracer *type) {
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 4/7 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
@@ -8036,6 +8036,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 ) {return 0 ; }/* 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
maintainerPATCH 5/7 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 | 5 +++++ 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, 58 insertions(+), 1 deletion(-)
include/linux/ftrace.h +5 -0
@@ -146,6 +146,10 @@ struct ftrace_ops_hash {struct ftrace_hash *filter_hash; struct mutex regex_lock; }; + +void ftrace_free_mem (void *start,void *end); +#else +static inline void ftrace_free_mem (void *start,void *end) { }#endif /*
@@ -262,6 +266,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
@@ -65,6 +65,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>
@@ -6605,6 +6606,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
maintainerPATCH 6/7 tracing: Move trace_handle_return() out of line
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
Currently trace_handle_return() looks like this:
static inline enum print_line_t trace_handle_return(struct trace_seq *s) {
return trace_seq_has_overflowed(s) ?
TRACE_TYPE_PARTIAL_LINE : TRACE_TYPE_HANDLED;
}
Where trace_seq_overflowed(s) is:
static inline bool trace_seq_has_overflowed(struct trace_seq *s)
{
return s->full || seq_buf_has_overflowed(&s->seq);}
And seq_buf_has_overflowed(&s->seq) is:
static inline bool
seq_buf_has_overflowed(struct seq_buf *s)
{
return s->len > s->size;}
Making trace_handle_return() into:
return (s->full || (s->seq->len > s->seq->size)) ?
TRACE_TYPE_PARTIAL_LINE :
TRACE_TYPE_HANDLED;One would think this is not an issue to keep as an inline. But because this is used in the TRACE_EVENT() macro, it is extended for every tracepoint in the system. Taking a look at a single tracepoint x86_irq_vector (was the first one I randomly chosen). As trace_handle_return is used in the TRACE_EVENT() macro of trace_raw_output_##call() we disassemble trace_raw_output_x86_irq_vector and do a diff:
- is the original
+ is the out-of-line code
I removed identical lines that were different just due to different addresses.
tmp/irq-vec-ool renamed from tmp/irq-vec-orig +6 -11
@@ -6,27 +6,23 @@ 53 push %rbx 48 89 fb mov %rdi,%rbx 4c 8b a7 c0 20 00 00 mov 0x20c0(%rdi),%r12 e8 f7 72 13 00 callq ffffffff81155c80 <trace_raw_output_prep> 83 f8 01 cmp $0x1,%eax 74 05 je ffffffff8101e993 <trace_raw_output_x86_irq_vector+0x23> 5b pop %rbx 41 5c pop %r12 5d pop %rbp c3 retq 41 8b 54 24 08 mov 0x8(%r12),%edx - 48 8d bb 98 10 00 00 lea 0x1098(%rbx),%rdi + 48 81 c3 98 10 00 00 add $0x1098,%rbx - 48 c7 c6 7b 8a a0 81 mov $0xffffffff81a08a7b,%rsi + 48 c7 c6 ab 8a a0 81 mov $0xffffffff81a08aab,%rsi - e8 c5 85 13 00 callq ffffffff81156f70 <trace_seq_printf> === here's the start of the main difference === + 48 89 df mov %rbx,%rdi + e8 62 7e 13 00 callq ffffffff81156810 <trace_seq_printf> - 8b 93 b8 20 00 00 mov 0x20b8(%rbx),%edx - 31 c0 xor %eax,%eax - 85 d2 test %edx,%edx - 75 11 jne ffffffff8101e9c8 <trace_raw_output_x86_irq_vector+0x58> - 48 8b 83 a8 20 00 00 mov 0x20a8(%rbx),%rax - 48 39 83 a0 20 00 00 cmp %rax,0x20a0(%rbx) - 0f 93 c0 setae %al + 48 89 df mov %rbx,%rdi + e8 4a c5 12 00 callq ffffffff8114af00 <trace_handle_return> 5b pop %rbx - 0f b6 c0 movzbl %al,%eax
=== end ===
41 5c pop %r12
5d pop %rbp
c3 retqIf you notice, the original has 22 bytes of text more than the out of line version. As this is for every TRACE_EVENT() defined in the system, this can become quite large.
text data bss dec hex filename
8690305 5450490 1298432 15439227 eb957b vmlinux-orig
8681725 5450490 1298432 15430647 eb73f7 vmlinux-handle
This change has a total of 8580 bytes in savings.
$ objdump -dr /tmp/vmlinux-orig | grep '^[0-9a-f]* <trace_raw_output' | wc -l 324
That's 324 tracepoints. But this does not include modules (which contain many more tracepoints). For an allyesconfig build:
$ objdump -dr vmlinux-allyes-orig | grep '^[0-9a-f]* <trace_raw_output' | wc -l 1401
That's 1401 tracepoints giving us:
text data bss dec hex filename
137920629 140221067 53264384 331406080 13c0db00 vmlinux-allyes-orig 137827709 140221067 53264384 331313160 13bf7008 vmlinux-allyes-handle
92920 bytes in savings!!!
--- include/linux/trace_events.h | 11 +---------- kernel/trace/trace.c | 12 ++++++++++++ 2 files changed, 13 insertions(+), 10 deletions(-)
include/linux/trace_events.h +1 -10
@@ -138,16 +138,7 @@ enum print_line_t {TRACE_TYPE_NO_CONSUME =3 /* Handled but ask to not consume */ }; -/* -* Several functions return TRACE_TYPE_PARTIAL_LINE if the trace_seq -* overflowed, and TRACE_TYPE_HANDLED otherwise. This helper function -* simplifies those functions and keeps them in sync. -*/ -static inline enum print_line_t trace_handle_return (struct trace_seq *s) -{ -return trace_seq_has_overflowed (s) ? -TRACE_TYPE_PARTIAL_LINE :TRACE_TYPE_HANDLED ; -} +enum print_line_t trace_handle_return (struct trace_seq *s); void tracing_generic_entry_update(struct trace_entry *entry, unsigned long flags,
kernel/trace/trace.c +12 -0
@@ -1998,6 +1998,18 @@ void tracing_record_cmdline(struct task_struct *tsk)__this_cpu_write (trace_cmdline_save, false); } +/* +* Several functions return TRACE_TYPE_PARTIAL_LINE if the trace_seq +* overflowed, and TRACE_TYPE_HANDLED otherwise. This helper function +* simplifies those functions and keeps them in sync. +*/ +enum print_line_t trace_handle_return (struct trace_seq *s) +{ +return trace_seq_has_overflowed (s) ? +TRACE_TYPE_PARTIAL_LINE :TRACE_TYPE_HANDLED ; +} +EXPORT_SYMBOL_GPL (trace_handle_return); +void tracing_generic_entry_update (struct trace_entry *entry,unsigned long flags,int pc)
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 7/7 ftrace/x86: Do no run CPU sync when there is only one CPU online
In reply to Steven RostedtFrom: "Steven Rostedt (VMware)" <[email protected]>
Moving enabling of function tracing to early boot, even before scheduling is enabled, means that it is not safe to enable interrupts. When function tracing was enabled at boot up, it use to happen after scheduling and the other CPUs were brought up. That required running a sync across all CPUs when modifying the function hook locations in the code. To do the synchronization, interrupts had to be enabled. Now function tracing can be started before the other CPUs are brought up, and enabling interrupts in that case is dangerous. As only tho boot CPU is active, there is no reason to run the synchronization. If the online CPU count is one, do not bother doing the synchronization. This removes the need to enable interrupts.
--- arch/x86/kernel/ftrace.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-)
arch/x86/kernel/ftrace.c +7 -1
@@ -533,7 +533,13 @@ static void do_sync_core(void *data)static void run_sync (void ) { -int enable_irqs =irqs_disabled (); +int enable_irqs; + +/* No need to sync if there's only one CPU */ +if (num_online_cpus () ==1 ) +return ; + + enable_irqs =irqs_disabled ();/* We may be called with interrupts disabled (on bootup). */ if (enable_irqs)
Signature · 1 line
2.10.2