Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

Merge tag 'trace-3.19-2' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace

Pull tracing updates from Steven Rostedt:
"As the merge window is still open, and this code was not as complex as
I thought it might be. I'm pushing this in now.

This will allow Thomas to debug his irq work for 3.20.

This adds two new features:

1) Allow traceopoints to be enabled right after mm_init().

By passing in the trace_event= kernel command line parameter,
tracepoints can be enabled at boot up. For debugging things like
the initialization of interrupts, it is needed to have tracepoints
enabled very early. People have asked about this before and this
has been on my todo list. As it can be helpful for Thomas to debug
his upcoming 3.20 IRQ work, I'm pushing this now. This way he can
add tracepoints into the IRQ set up and have users enable them when
things go wrong.

2) Have the tracepoints printed via printk() (the console) when they
are triggered.

If the irq code locks up or reboots the box, having the tracepoint
output go into the kernel ring buffer is useless for debugging.
But being able to add the tp_printk kernel command line option
along with the trace_event= option will have these tracepoints
printed as they occur, and that can be really useful for debugging
early lock up or reboot problems.

This code is not that intrusive and it passed all my tests. Thomas
tried them out too and it works for his needs.

Link: http://lkml.kernel.org/r/20141214201609.126831471@goodmis.org"

* tag 'trace-3.19-2' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace:
tracing: Add tp_printk cmdline to have tracepoints go to printk()
tracing: Move enabling tracepoints to just after rcu_init()

+116 -8
+18
Documentation/kernel-parameters.txt
··· 3570 3570 See also Documentation/trace/ftrace.txt "trace options" 3571 3571 section. 3572 3572 3573 + tp_printk[FTRACE] 3574 + Have the tracepoints sent to printk as well as the 3575 + tracing ring buffer. This is useful for early boot up 3576 + where the system hangs or reboots and does not give the 3577 + option for reading the tracing buffer or performing a 3578 + ftrace_dump_on_oops. 3579 + 3580 + To turn off having tracepoints sent to printk, 3581 + echo 0 > /proc/sys/kernel/tracepoint_printk 3582 + Note, echoing 1 into this file without the 3583 + tracepoint_printk kernel cmdline option has no effect. 3584 + 3585 + ** CAUTION ** 3586 + 3587 + Having tracepoints sent to printk() and activating high 3588 + frequency tracepoints such as irq or sched, can cause 3589 + the system to live lock. 3590 + 3573 3591 traceoff_on_warning 3574 3592 [FTRACE] enable this option to disable tracing when a 3575 3593 warning is hit. This turns off "tracing_on". Tracing can
+7
include/linux/ftrace.h
··· 39 39 # define FTRACE_FORCE_LIST_FUNC 0 40 40 #endif 41 41 42 + /* Main tracing buffer and events set up */ 43 + #ifdef CONFIG_TRACING 44 + void trace_init(void); 45 + #else 46 + static inline void trace_init(void) { } 47 + #endif 42 48 43 49 struct module; 44 50 struct ftrace_hash; ··· 879 873 enum ftrace_dump_mode; 880 874 881 875 extern enum ftrace_dump_mode ftrace_dump_on_oops; 876 + extern int tracepoint_printk; 882 877 883 878 extern void disable_trace_on_warning(void); 884 879 extern int __disable_trace_on_warning;
+4
init/main.c
··· 578 578 local_irq_disable(); 579 579 idr_init_cache(); 580 580 rcu_init(); 581 + 582 + /* trace_printk() and trace points may be used after this */ 583 + trace_init(); 584 + 581 585 context_tracking_init(); 582 586 radix_tree_init(); 583 587 /* init some links before init_ISA_irqs() */
+7
kernel/sysctl.c
··· 623 623 .mode = 0644, 624 624 .proc_handler = proc_dointvec, 625 625 }, 626 + { 627 + .procname = "tracepoint_printk", 628 + .data = &tracepoint_printk, 629 + .maxlen = sizeof(tracepoint_printk), 630 + .mode = 0644, 631 + .proc_handler = proc_dointvec, 632 + }, 626 633 #endif 627 634 #ifdef CONFIG_KEXEC 628 635 {
+24 -1
kernel/trace/trace.c
··· 63 63 */ 64 64 bool __read_mostly tracing_selftest_disabled; 65 65 66 + /* Pipe tracepoints to printk */ 67 + struct trace_iterator *tracepoint_print_iter; 68 + int tracepoint_printk; 69 + 66 70 /* For tracers that don't implement custom flags */ 67 71 static struct tracer_opt dummy_tracer_opt[] = { 68 72 { } ··· 197 193 } 198 194 __setup("trace_clock=", set_trace_boot_clock); 199 195 196 + static int __init set_tracepoint_printk(char *str) 197 + { 198 + if ((strcmp(str, "=0") != 0 && strcmp(str, "=off") != 0)) 199 + tracepoint_printk = 1; 200 + return 1; 201 + } 202 + __setup("tp_printk", set_tracepoint_printk); 200 203 201 204 unsigned long long ns2usecs(cycle_t nsec) 202 205 { ··· 6909 6898 return ret; 6910 6899 } 6911 6900 6901 + void __init trace_init(void) 6902 + { 6903 + if (tracepoint_printk) { 6904 + tracepoint_print_iter = 6905 + kmalloc(sizeof(*tracepoint_print_iter), GFP_KERNEL); 6906 + if (WARN_ON(!tracepoint_print_iter)) 6907 + tracepoint_printk = 0; 6908 + } 6909 + tracer_alloc_buffers(); 6910 + init_ftrace_syscalls(); 6911 + trace_event_init(); 6912 + } 6913 + 6912 6914 __init static int clear_boot_tracer(void) 6913 6915 { 6914 6916 /* ··· 6941 6917 return 0; 6942 6918 } 6943 6919 6944 - early_initcall(tracer_alloc_buffers); 6945 6920 fs_initcall(tracer_init_debugfs); 6946 6921 late_initcall(clear_boot_tracer);
+14
kernel/trace/trace.h
··· 1301 1301 #define perf_ftrace_event_register NULL 1302 1302 #endif 1303 1303 1304 + #ifdef CONFIG_FTRACE_SYSCALLS 1305 + void init_ftrace_syscalls(void); 1306 + #else 1307 + static inline void init_ftrace_syscalls(void) { } 1308 + #endif 1309 + 1310 + #ifdef CONFIG_EVENT_TRACING 1311 + void trace_event_init(void); 1312 + #else 1313 + static inline void __init trace_event_init(void) { } 1314 + #endif 1315 + 1316 + extern struct trace_iterator *tracepoint_print_iter; 1317 + 1304 1318 #endif /* _LINUX_KERNEL_TRACE_H */
+40 -2
kernel/trace/trace_events.c
··· 212 212 } 213 213 EXPORT_SYMBOL_GPL(ftrace_event_buffer_reserve); 214 214 215 + static DEFINE_SPINLOCK(tracepoint_iter_lock); 216 + 217 + static void output_printk(struct ftrace_event_buffer *fbuffer) 218 + { 219 + struct ftrace_event_call *event_call; 220 + struct trace_event *event; 221 + unsigned long flags; 222 + struct trace_iterator *iter = tracepoint_print_iter; 223 + 224 + if (!iter) 225 + return; 226 + 227 + event_call = fbuffer->ftrace_file->event_call; 228 + if (!event_call || !event_call->event.funcs || 229 + !event_call->event.funcs->trace) 230 + return; 231 + 232 + event = &fbuffer->ftrace_file->event_call->event; 233 + 234 + spin_lock_irqsave(&tracepoint_iter_lock, flags); 235 + trace_seq_init(&iter->seq); 236 + iter->ent = fbuffer->entry; 237 + event_call->event.funcs->trace(iter, 0, event); 238 + trace_seq_putc(&iter->seq, 0); 239 + printk("%s", iter->seq.buffer); 240 + 241 + spin_unlock_irqrestore(&tracepoint_iter_lock, flags); 242 + } 243 + 215 244 void ftrace_event_buffer_commit(struct ftrace_event_buffer *fbuffer) 216 245 { 246 + if (tracepoint_printk) 247 + output_printk(fbuffer); 248 + 217 249 event_trigger_unlock_commit(fbuffer->ftrace_file, fbuffer->buffer, 218 250 fbuffer->event, fbuffer->entry, 219 251 fbuffer->flags, fbuffer->pc); ··· 2512 2480 #endif 2513 2481 return 0; 2514 2482 } 2515 - early_initcall(event_trace_memsetup); 2516 - core_initcall(event_trace_enable); 2483 + 2484 + void __init trace_event_init(void) 2485 + { 2486 + event_trace_memsetup(); 2487 + init_ftrace_syscalls(); 2488 + event_trace_enable(); 2489 + } 2490 + 2517 2491 fs_initcall(event_trace_init); 2518 2492 2519 2493 #ifdef CONFIG_FTRACE_STARTUP_TEST
+2 -5
kernel/trace/trace_syscalls.c
··· 514 514 return (unsigned long)sys_call_table[nr]; 515 515 } 516 516 517 - static int __init init_ftrace_syscalls(void) 517 + void __init init_ftrace_syscalls(void) 518 518 { 519 519 struct syscall_metadata *meta; 520 520 unsigned long addr; ··· 524 524 GFP_KERNEL); 525 525 if (!syscalls_metadata) { 526 526 WARN_ON(1); 527 - return -ENOMEM; 527 + return; 528 528 } 529 529 530 530 for (i = 0; i < NR_syscalls; i++) { ··· 536 536 meta->syscall_nr = i; 537 537 syscalls_metadata[i] = meta; 538 538 } 539 - 540 - return 0; 541 539 } 542 - early_initcall(init_ftrace_syscalls); 543 540 544 541 #ifdef CONFIG_PERF_EVENTS 545 542