[2.6.40/2.8.0/3.0] tracing: clean ups and fixes
Subsystems (9)
Steven Rostedt
maintainerIngo,
I noticed I had a queue pending for this release that I was waiting on ACKS on. I received the acks but forgot to push this to you.
I added a couple more fixes (at the end) and ran this through my tests. This is the last of the patches I have for the merge window. Anything else will be strictly bug fixes.
I'm hoping to start on libperf.so after this (for 2.6.41 or 2.8.1? or 3.1?)
Please pull the latest tip/perf/urgent tree, which can be found at:
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/urgent
Jiri Olsa (1):
jump_label: Check entries limit in __jump_label_update
Masami Hiramatsu (1):
tracing/kprobes: Fix kprobe-tracer to support stack trace
Rabin Vincent (1):
ftrace/recordmcount: Avoid STT_FUNC symbols as base on ARM
Rakib Mullick (1):
x86/ftrace: Fix compiler warning in ftrace.c
Steven Rostedt (6):
maccess,probe_kernel: Make write/read src const void * scripts/tags.sh: Fix ctags for DEFINE_EVENT() scripts/tags.sh: Add magic for trace-events for etags too
ftrace: Have ftrace_startup() return failure code
tracing: Have event with function tracer check error return
ftrace: Set ops->flag to enabled even on static function tracing
Vaibhav Nagarnaik (2):
tracing: Schedule a delayed work to call wakeup()
tracing: Use NUMA allocation for per-cpu ring buffer pages
----
arch/blackfin/mm/maccess.c | 4 +- arch/s390/mm/maccess.c | 4 +- arch/x86/kernel/ftrace.c | 12 +++--- include/linux/ftrace_event.h | 4 ++ include/linux/ring_buffer.h | 2 +- include/linux/uaccess.h | 8 ++-- kernel/jump_label.c | 18 +++++++--- kernel/trace/ftrace.c | 18 ++++++--- kernel/trace/ring_buffer.c | 36 ++++++++++--------- kernel/trace/ring_buffer_benchmark.c | 2 +- kernel/trace/trace.c | 64 ++++++++++++++++++++++++--------- kernel/trace/trace.h | 9 +++++ kernel/trace/trace_events.c | 7 +++- kernel/trace/trace_kprobe.c | 6 ++- mm/maccess.c | 8 ++-- scripts/recordmcount.h | 8 ++++ scripts/tags.sh | 6 ++- 17 files changed, 145 insertions(+), 71 deletions(-)
Steven Rostedt
maintainerPATCH 1/12 maccess,probe_kernel: Make write/read src const void *
From: Steven Rostedt <[email protected]>
The functions probe_kernel_write() and probe_kernel_read() do not modify the src pointer. Allow const pointers to be passed in without the need of a typecast.
--- arch/blackfin/mm/maccess.c | 4 ++-- arch/s390/mm/maccess.c | 4 ++-- include/linux/uaccess.h | 8 ++++---- mm/maccess.c | 8 ++++---- 4 files changed, 12 insertions(+), 12 deletions(-)
arch/blackfin/mm/maccess.c +2 -2
@@ -16,7 +16,7 @@ static int validate_memory_access_address(unsigned long addr, int size)return bfin_mem_access_type (addr, size); } -long probe_kernel_read (void *dst,void *src,size_t size) +long probe_kernel_read (void *dst,const void *src,size_t size) {unsigned long lsrc = (unsigned long )src;int mem_type;
@@ -55,7 +55,7 @@ long probe_kernel_read(void *dst, void *src, size_t size)return -EFAULT ; } -long probe_kernel_write (void *dst,void *src,size_t size) +long probe_kernel_write (void *dst,const void *src,size_t size) {unsigned long ldst = (unsigned long )dst;int mem_type;
arch/s390/mm/maccess.c +2 -2
@@ -19,7 +19,7 @@* using the stura instruction. * Returns the number of bytes copied or -EFAULT. */ -static long probe_kernel_write_odd (void *dst,void *src,size_t size) +static long probe_kernel_write_odd (void *dst,const void *src,size_t size) {unsigned long count, aligned;int offset, mask;
@@ -45,7 +45,7 @@ static long probe_kernel_write_odd(void *dst, void *src, size_t size)return rc ? rc : count; } -long probe_kernel_write (void *dst,void *src,size_t size) +long probe_kernel_write (void *dst,const void *src,size_t size) {long copied =0 ;
include/linux/uaccess.h +4 -4
@@ -93,8 +93,8 @@ static inline unsigned long __copy_from_user_nocache(void *to,* Safely read from address @src to the buffer at @dst. If a kernel fault * happens, handle that and return -EFAULT. */ -extern long probe_kernel_read (void *dst,void *src,size_t size); -extern long __probe_kernel_read (void *dst,void *src,size_t size); +extern long probe_kernel_read (void *dst,const void *src,size_t size); +extern long __probe_kernel_read (void *dst,const void *src,size_t size);/* * probe_kernel_write(): safely attempt to write to a location
@@ -105,7 +105,7 @@ extern long __probe_kernel_read(void *dst, void *src, size_t size);* Safely write to address @dst from the buffer at @src. If a kernel fault * happens, handle that and return -EFAULT. */ -extern long notrace probe_kernel_write (void *dst,void *src,size_t size); -extern long notrace __probe_kernel_write (void *dst,void *src,size_t size); +extern long notrace probe_kernel_write (void *dst,const void *src,size_t size); +extern long notrace __probe_kernel_write (void *dst,const void *src,size_t size);#endif /* __LINUX_UACCESS_H__ */
mm/maccess.c +4 -4
@@ -15,10 +15,10 @@* happens, handle that and return -EFAULT. */ -long __weak probe_kernel_read (void *dst,void *src,size_t size) +long __weak probe_kernel_read (void *dst,const void *src,size_t size) __attribute__((alias ("__probe_kernel_read" ))); -long __probe_kernel_read (void *dst,void *src,size_t size) +long __probe_kernel_read (void *dst,const void *src,size_t size) {long ret;mm_segment_t old_fs =get_fs ();
@@ -43,10 +43,10 @@ EXPORT_SYMBOL_GPL(probe_kernel_read);* Safely write to address @dst from the buffer at @src. If a kernel fault * happens, handle that and return -EFAULT. */ -long __weak probe_kernel_write (void *dst,void *src,size_t size) +long __weak probe_kernel_write (void *dst,const void *src,size_t size) __attribute__((alias ("__probe_kernel_write" ))); -long __probe_kernel_write (void *dst,void *src,size_t size) +long __probe_kernel_write (void *dst,const void *src,size_t size) {long ret;mm_segment_t old_fs =get_fs ();
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 2/12 x86/ftrace: Fix compiler warning in ftrace.c
In reply to Steven RostedtFrom: Rakib Mullick <[email protected]>
Due to commit dc326fca2b64 (x86, cpu: Clean up and unify the NOP selection infrastructure), we get the following warning:
arch/x86/kernel/ftrace.c: In function ‘ftrace_make_nop’:arch/x86/kernel/ftrace.c:308:6: warning: assignment discards qualifiers from pointer target type arch/x86/kernel/ftrace.c: In function ‘ftrace_make_call’:arch/x86/kernel/ftrace.c:318:6: warning: assignment discards qualifiers from pointer target type
ftrace_nop_replace() now returns const unsigned char *, so change its associated function/variable to its compatible type to keep compiler clam.
[ updated for change of const void *src in probe_kernel_write() ]
--- arch/x86/kernel/ftrace.c | 12 ++++++------ 1 files changed, 6 insertions(+), 6 deletions(-)
arch/x86/kernel/ftrace.c +6 -6
@@ -123,7 +123,7 @@ static unsigned char *ftrace_call_replace(unsigned long ip, unsigned long addr)static atomic_t nmi_running =ATOMIC_INIT (0 );static int mod_code_status;/* holds return value of text write */ static void *mod_code_ip;/* holds the IP to write to */ -static void *mod_code_newcode;/* holds the text to write to the IP */ +static const void *mod_code_newcode;/* holds the text to write to the IP */ static unsigned nmi_wait_count;static atomic_t nmi_update_count =ATOMIC_INIT (0 );
@@ -225,7 +225,7 @@ within(unsigned long addr, unsigned long start, unsigned long end) }static int -do_ftrace_mod_code (unsigned long ip,void *new_code) +do_ftrace_mod_code (unsigned long ip,const void *new_code) {/* * On x86_64, kernel text mappings are mapped read-only with
@@ -266,8 +266,8 @@ static const unsigned char *ftrace_nop_replace(void) }static int -ftrace_modify_code (unsigned long ip,unsigned char *old_code, -unsigned char *new_code) +ftrace_modify_code (unsigned long ip,unsigned const char *old_code, +unsigned const char *new_code) {unsigned char replaced[MCOUNT_INSN_SIZE ];
@@ -301,7 +301,7 @@ ftrace_modify_code(unsigned long ip, unsigned char *old_code,int ftrace_make_nop (struct module *mod,struct dyn_ftrace *rec,unsigned long addr) { -unsigned char *new, *old; +unsigned const char *new, *old;unsigned long ip = rec->ip; old =ftrace_call_replace (ip, addr);
@@ -312,7 +312,7 @@ int ftrace_make_nop(struct module *mod,int ftrace_make_call (struct dyn_ftrace *rec,unsigned long addr) { -unsigned char *new, *old; +unsigned const char *new, *old;unsigned long ip = rec->ip; old =ftrace_nop_replace ();
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 3/12 scripts/tags.sh: Fix ctags for DEFINE_EVENT()
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
The regex to handle DEFINE_EVENT() should not be the same as the TRACE_EVENT() as the first parameter in DEFINE_EVENT is the template name, not the event name. We need the second parameter as that is what the trace_... will use.
--- scripts/tags.sh | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)
scripts/tags.sh +1 -1
@@ -132,7 +132,7 @@ exuberant() --regex-asm='/^ENTRY\(([^)]*)\).*/\1/' \ --regex-c='/^SYSCALL_DEFINE[[:digit:]]?\(([^,)]*).*/sys_\1/' \ --regex-c++='/^TRACE_EVENT\(([^,)]*).*/trace_\1/' \ - --regex-c++='/^DEFINE_EVENT\(([^,)]*).*/trace_\1/' + --regex-c++='/^DEFINE_EVENT\([^,)]*, *([^,)]*).*/trace_\1/' all_kconfigs | xargs $1 -a \ --langdef=kconfig --language-force=kconfig \
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 4/12 scripts/tags.sh: Add magic for trace-events for etags too
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
Seems that Peter Zijlstra treats us emacs users as second class citizens and the commit:
commit 15664125f7cadcb6d725cb2d9b90f9715397848d
Author: Peter Zijlstra <[email protected]>
scripts/tags.sh: Add magic for trace-events
only updated ctags (for vim) and did not do the work to let us lowly emacs users benefit from such a change.
--- scripts/tags.sh | 4 +++- 1 files changed, 3 insertions(+), 1 deletions(-)
scripts/tags.sh +3 -1
@@ -152,7 +152,9 @@ emacs() { all_sources | xargs $1 -a \ --regex='/^ENTRY(\([^)]*\)).*/\1/' \ - --regex='/^SYSCALL_DEFINE[0-9]?(\([^,)]*\).*/sys_\1/' + --regex='/^SYSCALL_DEFINE[0-9]?(\([^,)]*\).*/sys_\1/' \ + --regex='/^TRACE_EVENT(\([^,)]*\).*/trace_\1/' \ + --regex='/^DEFINE_EVENT([^,)]*, *\([^,)]*\).*/trace_\1/' all_kconfigs | xargs $1 -a \ --regex='/^[ \t]*\(\(menu\)*config\)[ \t]+\([a-zA-Z0-9_]+\)/\3/'
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 5/12 ftrace/recordmcount: Avoid STT_FUNC symbols as base on ARM
In reply to Steven RostedtFrom: Rabin Vincent <[email protected]>
While find_secsym_ndx often finds the unamed local STT_SECTION, if a section has only one function in it, the ARM toolchain generates the STT_FUNC symbol before the STT_SECTION, and recordmcount finds this instead.
This is problematic on ARM because in ARM ELFs, "if a [STT_FUNC] symbol addresses a Thumb instruction, its value is the address of the instruction with bit zero set (in a relocatable object, the section offset with bit zero set)". This leads to incorrect mcount addresses being recorded.
Fix this by not using STT_FUNC symbols as the base on ARM.
--- scripts/recordmcount.h | 8 ++++++++ 1 files changed, 8 insertions(+), 0 deletions(-)
scripts/recordmcount.h +8 -0
@@ -43,6 +43,7 @@#undef ELF_R_INFO#undef Elf_r_info#undef ELF_ST_BIND +#undef ELF_ST_TYPE#undef fn_ELF_R_SYM#undef fn_ELF_R_INFO#undef uint_t
@@ -76,6 +77,7 @@# define ELF_R_INFO ELF64_R_INFO# define Elf_r_info Elf64_r_info# define ELF_ST_BIND ELF64_ST_BIND +# define ELF_ST_TYPE ELF64_ST_TYPE# define fn_ELF_R_SYM fn_ELF64_R_SYM# define fn_ELF_R_INFO fn_ELF64_R_INFO# define uint_t uint64_t
@@ -108,6 +110,7 @@# define ELF_R_INFO ELF32_R_INFO# define Elf_r_info Elf32_r_info# define ELF_ST_BIND ELF32_ST_BIND +# define ELF_ST_TYPE ELF32_ST_TYPE# define fn_ELF_R_SYM fn_ELF32_R_SYM# define fn_ELF_R_INFO fn_ELF32_R_INFO# define uint_t uint32_t
@@ -427,6 +430,11 @@ static unsigned find_secsym_ndx(unsigned const txtndx,if (txtndx ==w2 (symp->st_shndx)/* avoid STB_WEAK */ && (STB_LOCAL == st_bind ||STB_GLOBAL == st_bind)) { +/* function symbols on ARM have quirks, avoid them */ +if (w2 (ehdr->e_machine) ==EM_ARM + &&ELF_ST_TYPE (symp->st_info) ==STT_FUNC ) +continue ; + *recvalp =_w (symp->st_value);return symp - sym0; }
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 6/12 tracing: Schedule a delayed work to call wakeup()
In reply to Steven RostedtFrom: Vaibhav Nagarnaik <[email protected]>
In using syscall tracing by concurrent processes, the wakeup() that is called in the event commit function causes contention on the spin lock of the waitqueue. I enabled sys_enter_getuid and sys_exit_getuid tracepoints, and by running getuid_microbench from autotest in parallel I found that the contention causes exponential latency increase in the tracing path.
The autotest binary getuid_microbench calls getuid() in a tight loop for the given number of iterations and measures the average time required to complete a single invocation of syscall.
The patch schedules a delayed work after 2 ms once an event commit calls to wake up the trace wait_queue. This removes the delay caused by contention on spin lock in wakeup() and amortizes the wakeup() calls scheduled over the 2 ms period.
In the following example, the script enables the sys_enter_getuid and sys_exit_getuid tracepoints and runs the getuid_microbench in parallel with the given number of processes. The output clearly shows the latency increase caused by contentions.
$ ~/getuid.sh 1 1000000 calls in 0.720974253 s (720.974253 ns/call)
$ ~/getuid.sh 2 1000000 calls in 1.166457554 s (1166.457554 ns/call) 1000000 calls in 1.168933765 s (1168.933765 ns/call)
$ ~/getuid.sh 3 1000000 calls in 1.783827516 s (1783.827516 ns/call) 1000000 calls in 1.795553270 s (1795.553270 ns/call) 1000000 calls in 1.796493376 s (1796.493376 ns/call)
$ ~/getuid.sh 4 1000000 calls in 4.483041796 s (4483.041796 ns/call) 1000000 calls in 4.484165388 s (4484.165388 ns/call) 1000000 calls in 4.484850762 s (4484.850762 ns/call) 1000000 calls in 4.485643576 s (4485.643576 ns/call)
$ ~/getuid.sh 5 1000000 calls in 6.497521653 s (6497.521653 ns/call) 1000000 calls in 6.502000236 s (6502.000236 ns/call) 1000000 calls in 6.501709115 s (6501.709115 ns/call) 1000000 calls in 6.502124100 s (6502.124100 ns/call) 1000000 calls in 6.502936358 s (6502.936358 ns/call)
After the patch, the latencies scale better. 1000000 calls in 0.728720455 s (728.720455 ns/call)
1000000 calls in 0.842782857 s (842.782857 ns/call) 1000000 calls in 0.883803135 s (883.803135 ns/call)
1000000 calls in 0.902077764 s (902.077764 ns/call) 1000000 calls in 0.902838202 s (902.838202 ns/call) 1000000 calls in 0.908896885 s (908.896885 ns/call)
1000000 calls in 0.932523515 s (932.523515 ns/call) 1000000 calls in 0.958009672 s (958.009672 ns/call) 1000000 calls in 0.986188020 s (986.188020 ns/call) 1000000 calls in 0.989771102 s (989.771102 ns/call)
1000000 calls in 0.933518391 s (933.518391 ns/call) 1000000 calls in 0.958897947 s (958.897947 ns/call) 1000000 calls in 1.031038897 s (1031.038897 ns/call) 1000000 calls in 1.089516025 s (1089.516025 ns/call) 1000000 calls in 1.141998347 s (1141.998347 ns/call)
--- kernel/trace/trace.c | 23 ++++++++++++----------- 1 files changed, 12 insertions(+), 11 deletions(-)
kernel/trace/trace.c +12 -11
@@ -343,26 +343,27 @@ unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |static int trace_stop_count;static DEFINE_SPINLOCK (tracing_start_lock); +static void wakeup_work_handler (struct work_struct *work) +{ +wake_up (&trace_wait); +} + +static DECLARE_DELAYED_WORK(wakeup_work, wakeup_work_handler); +/** * trace_wake_up - wake up tasks waiting for trace input * -* Simply wakes up any task that is blocked on the trace_wait -* queue. These is used with trace_poll for tasks polling the trace. +* Schedules a delayed work to wake up any task that is blocked on the +* trace_wait queue. These is used with trace_poll for tasks polling the +* trace. */ void trace_wake_up (void ) { -int cpu; +const unsigned long delay =msecs_to_jiffies (2 );//delay 2 ms if (trace_flags &TRACE_ITER_BLOCK )return ; -/* -* The runqueue_is_locked() can fail, but this is the best we -* have for now: -*/ - cpu =get_cpu (); -if (!runqueue_is_locked (cpu)) -wake_up (&trace_wait); -put_cpu (); +schedule_delayed_work (&wakeup_work, delay); }static int __init set_buf_size (char *str)
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 7/12 jump_label: Check entries limit in __jump_label_update
In reply to Steven RostedtFrom: Jiri Olsa <[email protected]>
When iterating the jump_label entries array (core or modules), the __jump_label_update function peeks over the last entry.
The reason is that the end of the for loop depends on the key value of the processed entry. Thus when going through the last array entry, we will touch the memory behind the array limit.
This bug probably will never be triggered, since most likely the memory behind the jump_label entries will be accesable and the entry->key will be different than the expected value.
--- kernel/jump_label.c | 18 +++++++++++++----- 1 files changed, 13 insertions(+), 5 deletions(-)
kernel/jump_label.c +13 -5
@@ -105,9 +105,12 @@ static int __jump_label_text_reserved(struct jump_entry *iter_start, }static void __jump_label_update (struct jump_label_key *key, -struct jump_entry *entry,int enable) +struct jump_entry *entry, +struct jump_entry *stop,int enable) { -for (; entry->key == (jump_label_t )(unsigned long )key; entry++) { +for (; (entry < stop) && + (entry->key == (jump_label_t )(unsigned long )key); + entry++) {/* * entry->code set to 0 invalidates module init text sections * kernel_text_address() verifies we are not in core kernel
@@ -181,7 +184,11 @@ static void __jump_label_mod_update(struct jump_label_key *key, int enable)struct jump_label_mod *mod = key->next;while (mod) { -__jump_label_update (key, mod->entries, enable); +struct module *m = mod->mod; + +__jump_label_update (key, mod->entries, + m->jump_entries + m->num_jump_entries, + enable); mod = mod->next; } }
@@ -245,7 +252,8 @@ static int jump_label_add_module(struct module *mod) key->next = jlm;if (jump_label_enabled (key)) -__jump_label_update (key, iter,JUMP_LABEL_ENABLE ); +__jump_label_update (key, iter, iter_stop, +JUMP_LABEL_ENABLE ); }return 0 ;
@@ -371,7 +379,7 @@ static void jump_label_update(struct jump_label_key *key, int enable)/* if there are no users, entry can be NULL */ if (entry) -__jump_label_update (key, entry, enable); +__jump_label_update (key, entry, __stop___jump_table, enable);#ifdef CONFIG_MODULES __jump_label_mod_update (key, enable);
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 8/12 tracing/kprobes: Fix kprobe-tracer to support stack trace
In reply to Steven RostedtFrom: Masami Hiramatsu <[email protected]>
Fix to support kernel stack trace correctly on kprobe-tracer. Since the execution path of kprobe-based dynamic events is different from other tracepoint-based events, normal ftrace_trace_stack() doesn't work correctly. To fix that, this introduces ftrace_trace_stack_regs() which traces stack via pt_regs instead of current stack register.
e.g.
# echo p schedule > /sys/kernel/debug/tracing/kprobe_events
# echo 1 > /sys/kernel/debug/tracing/options/stacktrace
# echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable
# head -n 20 /sys/kernel/debug/tracing/trace
sshd-1549 [001] 857.326335: p_schedule_0: (schedule+0x0/0x900)
sshd-1549 [001] 857.326337: <stack trace>
=> schedule_hrtimeout_range
=> poll_schedule_timeout
=> do_select
=> core_sys_select
=> sys_select
=> system_call_fastpath
tee-1751 [000] 857.326394: p_schedule_0: (schedule+0x0/0x900)
tee-1751 [000] 857.326395: <stack trace>
=> do_group_exit
=> sys_exit_group
=> system_call_fastpath
<idle>-0 [001] 857.326406: p_schedule_0: (schedule+0x0/0x900)
<idle>-0 [001] 857.326407: <stack trace>
=> start_secondary--- include/linux/ftrace_event.h | 4 ++++ kernel/trace/trace.c | 35 ++++++++++++++++++++++++++++++----- kernel/trace/trace.h | 9 +++++++++ kernel/trace/trace_kprobe.c | 6 ++++-- 4 files changed, 47 insertions(+), 7 deletions(-)
include/linux/ftrace_event.h +4 -0
@@ -117,6 +117,10 @@ void trace_current_buffer_unlock_commit(struct ring_buffer *buffer,void trace_nowake_buffer_unlock_commit (struct ring_buffer *buffer,struct ring_buffer_event *event,unsigned long flags,int pc); +void trace_nowake_buffer_unlock_commit_regs (struct ring_buffer *buffer, +struct ring_buffer_event *event, +unsigned long flags,int pc, +struct pt_regs *regs);void trace_current_buffer_discard_commit (struct ring_buffer *buffer,struct ring_buffer_event *event);
kernel/trace/trace.c +30 -5
@@ -1192,6 +1192,18 @@ void trace_nowake_buffer_unlock_commit(struct ring_buffer *buffer, }EXPORT_SYMBOL_GPL (trace_nowake_buffer_unlock_commit); +void trace_nowake_buffer_unlock_commit_regs (struct ring_buffer *buffer, +struct ring_buffer_event *event, +unsigned long flags,int pc, +struct pt_regs *regs) +{ +ring_buffer_unlock_commit (buffer, event); + +ftrace_trace_stack_regs (buffer, flags,0 , pc, regs); +ftrace_trace_userstack (buffer, flags, pc); +} +EXPORT_SYMBOL_GPL (trace_nowake_buffer_unlock_commit_regs); +void trace_current_buffer_discard_commit (struct ring_buffer *buffer,struct ring_buffer_event *event) {
@@ -1237,7 +1249,7 @@ ftrace(struct trace_array *tr, struct trace_array_cpu *data,#ifdef CONFIG_STACKTRACE static void __ftrace_trace_stack (struct ring_buffer *buffer,unsigned long flags, -int skip,int pc) +int skip,int pc,struct pt_regs *regs) {struct ftrace_event_call *call = &event_kernel_stack;struct ring_buffer_event *event;
@@ -1256,24 +1268,36 @@ static void __ftrace_trace_stack(struct ring_buffer *buffer, trace.skip = skip; trace.entries = entry->caller; -save_stack_trace (&trace); +if (regs) +save_stack_trace_regs (&trace, regs); +else +save_stack_trace (&trace);if (!filter_check_discard (call, entry, buffer, event))ring_buffer_unlock_commit (buffer, event); } +void ftrace_trace_stack_regs (struct ring_buffer *buffer,unsigned long flags, +int skip,int pc,struct pt_regs *regs) +{ +if (!(trace_flags &TRACE_ITER_STACKTRACE )) +return ; + +__ftrace_trace_stack (buffer, flags, skip, pc, regs); +} +void ftrace_trace_stack (struct ring_buffer *buffer,unsigned long flags,int skip,int pc) {if (!(trace_flags &TRACE_ITER_STACKTRACE ))return ; -__ftrace_trace_stack (buffer, flags, skip, pc); +__ftrace_trace_stack (buffer, flags, skip, pc,NULL ); }void __trace_stack (struct trace_array *tr,unsigned long flags,int skip,int pc) { -__ftrace_trace_stack (tr->buffer, flags, skip, pc); +__ftrace_trace_stack (tr->buffer, flags, skip, pc,NULL ); }/**
@@ -1289,7 +1313,8 @@ void trace_dump_stack(void)local_save_flags (flags);/* skipping 3 traces, seems to get us at the caller of this function */ -__ftrace_trace_stack (global_trace.buffer, flags,3 ,preempt_count ()); +__ftrace_trace_stack (global_trace.buffer, flags,3 ,preempt_count (), +NULL ); } static DEFINE_PER_CPU(int, user_stack_count);
kernel/trace/trace.h +9 -0
@@ -389,6 +389,9 @@ void update_max_tr_single(struct trace_array *tr,void ftrace_trace_stack (struct ring_buffer *buffer,unsigned long flags,int skip,int pc); +void ftrace_trace_stack_regs (struct ring_buffer *buffer,unsigned long flags, +int skip,int pc,struct pt_regs *regs); +void ftrace_trace_userstack (struct ring_buffer *buffer,unsigned long flags,int pc);
@@ -400,6 +403,12 @@ static inline void ftrace_trace_stack(struct ring_buffer *buffer, { } +static inline void ftrace_trace_stack_regs (struct ring_buffer *buffer, +unsigned long flags,int skip, +int pc,struct pt_regs *regs) +{ +} +static inline void ftrace_trace_userstack (struct ring_buffer *buffer,unsigned long flags,int pc) {
kernel/trace/trace_kprobe.c +4 -2
@@ -1397,7 +1397,8 @@ static __kprobes void kprobe_trace_func(struct kprobe *kp, struct pt_regs *regs)store_trace_args (sizeof (*entry), tp, regs, (u8 *)&entry[1 ], dsize);if (!filter_current_check_discard (buffer, call, entry, event)) -trace_nowake_buffer_unlock_commit (buffer, event, irq_flags, pc); +trace_nowake_buffer_unlock_commit_regs (buffer, event, + irq_flags, pc, regs); }/* Kretprobe handler */
@@ -1429,7 +1430,8 @@ static __kprobes void kretprobe_trace_func(struct kretprobe_instance *ri,store_trace_args (sizeof (*entry), tp, regs, (u8 *)&entry[1 ], dsize);if (!filter_current_check_discard (buffer, call, entry, event)) -trace_nowake_buffer_unlock_commit (buffer, event, irq_flags, pc); +trace_nowake_buffer_unlock_commit_regs (buffer, event, + irq_flags, pc, regs); }/* Event entry printers */
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 9/12 tracing: Use NUMA allocation for per-cpu ring buffer pages
In reply to Steven RostedtFrom: Vaibhav Nagarnaik <[email protected]>
The tracing ring buffer is a group of per-cpu ring buffers where allocation and logging is done on a per-cpu basis. The events that are generated on a particular CPU are logged in the corresponding buffer. This is to provide wait-free writes between CPUs and good NUMA node locality while accessing the ring buffer.
However, the allocation routines consider NUMA locality only for buffer page metadata and not for the actual buffer page. This causes the pages to be allocated on the NUMA node local to the CPU where the allocation routine is running at the time.
This patch fixes the problem by using a NUMA node specific allocation routine so that the pages are allocated from a NUMA node local to the logging CPU.
I tested with the getuid_microbench from autotest. It is a simple binary that calls getuid() in a loop and measures the average time for the syscall to complete. The following command was used to test:
$ getuid_microbench 1000000
Compared the numbers found on kernel with and without this patch and found that logging latency decreases by 30-50 ns/call. tracing with non-NUMA allocation - 569 ns/call
tracing with NUMA allocation - 512 ns/call
--- include/linux/ring_buffer.h | 2 +- kernel/trace/ring_buffer.c | 36 +++++++++++++++++---------------- kernel/trace/ring_buffer_benchmark.c | 2 +- kernel/trace/trace.c | 6 +++- 4 files changed, 25 insertions(+), 21 deletions(-)
include/linux/ring_buffer.h +1 -1
@@ -169,7 +169,7 @@ void ring_buffer_set_clock(struct ring_buffer *buffer,size_t ring_buffer_page_len (void *page); -void *ring_buffer_alloc_read_page (struct ring_buffer *buffer); +void *ring_buffer_alloc_read_page (struct ring_buffer *buffer,int cpu);void ring_buffer_free_read_page (struct ring_buffer *buffer,void *data);int ring_buffer_read_page (struct ring_buffer *buffer,void **data_page,size_t len,int cpu,int full);
kernel/trace/ring_buffer.c +19 -17
@@ -997,13 +997,13 @@ static int rb_allocate_pages(struct ring_buffer_per_cpu *cpu_buffer, unsigned nr_pages) {struct buffer_page *bpage, *tmp; -unsigned long addr;LIST_HEAD (pages);unsigned i;WARN_ON (!nr_pages);for (i =0 ; i < nr_pages; i++) { +struct page *page; bpage =kzalloc_node (ALIGN (sizeof (*bpage),cache_line_size ()),GFP_KERNEL ,cpu_to_node (cpu_buffer->cpu));if (!bpage)
@@ -1013,10 +1013,11 @@ static int rb_allocate_pages(struct ring_buffer_per_cpu *cpu_buffer,list_add (&bpage->list, &pages); - addr =__get_free_page (GFP_KERNEL ); -if (!addr) + page =alloc_pages_node (cpu_to_node (cpu_buffer->cpu), +GFP_KERNEL ,0 ); +if (!page) goto free_pages; - bpage->page = (void *)addr; + bpage->page =page_address (page);rb_init_page (bpage->page); }
@@ -1045,7 +1046,7 @@ rb_allocate_cpu_buffer(struct ring_buffer *buffer, int cpu) {struct ring_buffer_per_cpu *cpu_buffer;struct buffer_page *bpage; -unsigned long addr; +struct page *page;int ret; cpu_buffer = kzalloc_node(ALIGN(sizeof(*cpu_buffer), cache_line_size()),
@@ -1067,10 +1068,10 @@ rb_allocate_cpu_buffer(struct ring_buffer *buffer, int cpu)rb_check_bpage (cpu_buffer, bpage); cpu_buffer->reader_page = bpage; - addr =__get_free_page (GFP_KERNEL ); -if (!addr) + page =alloc_pages_node (cpu_to_node (cpu),GFP_KERNEL ,0 ); +if (!page) goto fail_free_reader; - bpage->page = (void *)addr; + bpage->page =page_address (page);rb_init_page (bpage->page);INIT_LIST_HEAD (&cpu_buffer->reader_page->list);
@@ -1314,7 +1315,6 @@ int ring_buffer_resize(struct ring_buffer *buffer, unsigned long size)unsigned nr_pages, rm_pages, new_pages;struct buffer_page *bpage, *tmp;unsigned long buffer_size; -unsigned long addr;LIST_HEAD (pages);int i, cpu;
@@ -1375,16 +1375,18 @@ int ring_buffer_resize(struct ring_buffer *buffer, unsigned long size)for_each_buffer_cpu (buffer, cpu) {for (i =0 ; i < new_pages; i++) { +struct page *page; bpage =kzalloc_node (ALIGN (sizeof (*bpage),cache_line_size ()),GFP_KERNEL ,cpu_to_node (cpu));if (!bpage) goto free_pages;list_add (&bpage->list, &pages); - addr =__get_free_page (GFP_KERNEL ); -if (!addr) + page =alloc_pages_node (cpu_to_node (cpu),GFP_KERNEL , +0 ); +if (!page) goto free_pages; - bpage->page = (void *)addr; + bpage->page =page_address (page);rb_init_page (bpage->page); } }
@@ -3730,16 +3732,16 @@ EXPORT_SYMBOL_GPL(ring_buffer_swap_cpu);* Returns: * The page allocated, or NULL on error. */ -void *ring_buffer_alloc_read_page (struct ring_buffer *buffer) +void *ring_buffer_alloc_read_page (struct ring_buffer *buffer,int cpu) {struct buffer_data_page *bpage; -unsigned long addr; +struct page *page; - addr =__get_free_page (GFP_KERNEL ); -if (!addr) + page =alloc_pages_node (cpu_to_node (cpu),GFP_KERNEL ,0 ); +if (!page)return NULL ; - bpage = (void *)addr; + bpage =page_address (page);rb_init_page (bpage);
kernel/trace/ring_buffer_benchmark.c +1 -1
@@ -106,7 +106,7 @@ static enum event_status read_page(int cpu)int inc;int i; - bpage =ring_buffer_alloc_read_page (buffer); + bpage =ring_buffer_alloc_read_page (buffer, cpu);if (!bpage)return EVENT_DROPPED ;
kernel/trace/trace.c +4 -2
@@ -3722,7 +3722,8 @@ tracing_buffers_read(struct file *filp, char __user *ubuf,return 0 ;if (!info->spare) - info->spare =ring_buffer_alloc_read_page (info->tr->buffer); + info->spare =ring_buffer_alloc_read_page (info->tr->buffer, + info->cpu);if (!info->spare)return -ENOMEM ;
@@ -3879,7 +3880,8 @@ tracing_buffers_splice_read(struct file *file, loff_t *ppos, ref->ref =1 ; ref->buffer = info->tr->buffer; - ref->page =ring_buffer_alloc_read_page (ref->buffer); + ref->page =ring_buffer_alloc_read_page (ref->buffer, + info->cpu);if (!ref->page) {kfree (ref);break ;
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 10/12 ftrace: Have ftrace_startup() return failure code
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
The register_ftrace_function() returns an error code on failure except if the call to ftrace_startup() fails. Add a error return to ftrace_startup() if it fails to start, allowing register_ftrace_funtion() to return a proper error value.
--- kernel/trace/ftrace.c | 14 ++++++++------ 1 files changed, 8 insertions(+), 6 deletions(-)
kernel/trace/ftrace.c +8 -6
@@ -1638,12 +1638,12 @@ static void ftrace_startup_enable(int command)ftrace_run_update_code (command); } -static void ftrace_startup (struct ftrace_ops *ops,int command) +static int ftrace_startup (struct ftrace_ops *ops,int command) {bool hash_enable = true;if (unlikely (ftrace_disabled)) -return ; +return -ENODEV ; ftrace_start_up++; command |=FTRACE_ENABLE_CALLS ;
@@ -1662,6 +1662,8 @@ static void ftrace_startup(struct ftrace_ops *ops, int command)ftrace_hash_rec_enable (ops,1 );ftrace_startup_enable (command); + +return 0 ; }static void ftrace_shutdown (struct ftrace_ops *ops,int command)
@@ -2501,7 +2503,7 @@ static void __enable_ftrace_function_probe(void) ret =__register_ftrace_function (&trace_probe_ops);if (!ret) -ftrace_startup (&trace_probe_ops,0 ); + ret =ftrace_startup (&trace_probe_ops,0 ); ftrace_probe_registered =1 ; }
@@ -3466,7 +3468,7 @@ device_initcall(ftrace_nodyn_init);static inline int ftrace_init_dyn_debugfs (struct dentry *d_tracer) {return 0 ; }static inline void ftrace_startup_enable (int command) { }/* Keep as macros so we do not need to define the commands */ -# define ftrace_startup (ops, command) do { } while (0) +# define ftrace_startup (ops, command) ({0;})# define ftrace_shutdown (ops, command) do { } while (0)# define ftrace_startup_sysctl () do { } while (0)# define ftrace_shutdown_sysctl () do { } while (0)
@@ -3799,7 +3801,7 @@ int register_ftrace_function(struct ftrace_ops *ops) ret =__register_ftrace_function (ops);if (!ret) -ftrace_startup (ops,0 ); + ret =ftrace_startup (ops,0 ); out_unlock:
@@ -4045,7 +4047,7 @@ int register_ftrace_graph(trace_func_graph_ret_t retfunc, ftrace_graph_return = retfunc; ftrace_graph_entry = entryfunc; -ftrace_startup (&global_ops,FTRACE_START_FUNC_RET ); + ret =ftrace_startup (&global_ops,FTRACE_START_FUNC_RET ); out:mutex_unlock (&ftrace_lock);
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 11/12 tracing: Have event with function tracer check error return
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
The self tests for event tracer does not check if the function tracing was successfully activated. It needs to before it continues the tests, otherwise the wrong errors may be reported.
--- kernel/trace/trace_events.c | 7 ++++++- 1 files changed, 6 insertions(+), 1 deletions(-)
kernel/trace/trace_events.c +6 -1
@@ -1657,7 +1657,12 @@ static struct ftrace_ops trace_ops __initdata =static __init void event_trace_self_test_with_function (void ) { -register_ftrace_function (&trace_ops); +int ret; + ret =register_ftrace_function (&trace_ops); +if (WARN_ON (ret <0 )) { +pr_info ("Failed to enable function tracer for event tests\n" ); +return ; + }pr_info ("Running tests again, along with the function tracer\n" );event_trace_self_tests ();unregister_ftrace_function (&trace_ops);
Signature · 1 line
1.7.4.4
Steven Rostedt
maintainerPATCH 12/12 ftrace: Set ops->flag to enabled even on static function tracing
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
When dynamic ftrace is not configured, the ops->flags still needs to have its FTRACE_OPS_FL_ENABLED bit set in ftrace_startup().
--- kernel/trace/ftrace.c | 6 +++++- 1 files changed, 5 insertions(+), 1 deletions(-)
kernel/trace/ftrace.c +5 -1
@@ -3468,7 +3468,11 @@ device_initcall(ftrace_nodyn_init);static inline int ftrace_init_dyn_debugfs (struct dentry *d_tracer) {return 0 ; }static inline void ftrace_startup_enable (int command) { }/* Keep as macros so we do not need to define the commands */ -# define ftrace_startup (ops, command) ({0;}) +# define ftrace_startup (ops, command) \ + ({ \ + (ops)->flags |= FTRACE_OPS_FL_ENABLED; \ + 0; \ + })# define ftrace_shutdown (ops, command) do { } while (0)# define ftrace_startup_sysctl () do { } while (0)# define ftrace_shutdown_sysctl () do { } while (0)
Signature · 1 line
1.7.4.4