tracing: Some micro optimizations
Subsystems (5)
Steven Rostedt
maintainercover tracing: Some micro optimizations
Andi Kleen pointed out a trace that showed lots of functions being called in the trace event hot path. These functions would help to be inlined. More needs to be done, but this is just a start.
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
for-next
Head SHA1: 38e11df134297ea3860c7aad8263ece27db01308
Steven Rostedt (Red Hat) (8):
tracing: Create a always_inlined __trace_buffer_lock_reserve()
ring-buffer: Make rb_reserve_next_event() always inlined
ring-buffer: Always inline rb_event_data()
tracing: Make tracepoint_printk a static_key
tracing: Make __buffer_unlock_commit() always_inline
ring-buffer: Force inline of hotpath helper functions
ring-buffer: Froce rb_update_write_stamp() to be inlined
ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline
----
include/linux/ftrace.h | 4 + kernel/sysctl.c | 2 +- kernel/trace/ring_buffer.c | 28 ++--- kernel/trace/trace.c | 206 ++++++++++++++++++++++++++--------- kernel/trace/trace.h | 4 +- kernel/trace/trace_branch.c | 2 +- kernel/trace/trace_events.c | 40 ------- kernel/trace/trace_functions_graph.c | 4 +- kernel/trace/trace_hwlat.c | 2 +- 9 files changed, 177 insertions(+), 115 deletions(-)
Steven Rostedt
maintainerPATCH 1/8 tracing: Create a always_inlined __trace_buffer_lock_reserve()
From: "Steven Rostedt (Red Hat)" <[email protected]>
As Andi Kleen pointed out in the Link below, the trace events has quite a bit of code execution. A lot of that happens to be calling functions, where some of them should simply be inlined. One of these functions happens to be trace_buffer_lock_reserve() which is also a global, but it is used throughout the file it is defined in. Create a __trace_buffer_lock_reserve() that is always inlined that the file can benefit from.
--- kernel/trace/trace.c | 87 +++++++++++++++++++++++++++++----------------------- 1 file changed, 48 insertions(+), 39 deletions(-)
kernel/trace/trace.c +48 -39
@@ -739,6 +739,31 @@ static inline void ftrace_trace_stack(struct trace_array *tr,#endif +static __always_inline void +trace_event_setup (struct ring_buffer_event *event, +int type,unsigned long flags,int pc) +{ +struct trace_entry *ent =ring_buffer_event_data (event); + +tracing_generic_entry_update (ent, flags, pc); + ent->type = type; +} + +static __always_inline struct ring_buffer_event * +__trace_buffer_lock_reserve (struct ring_buffer *buffer, +int type, +unsigned long len, +unsigned long flags,int pc) +{ +struct ring_buffer_event *event; + + event =ring_buffer_lock_reserve (buffer, len); +if (event !=NULL ) +trace_event_setup (event, type, flags, pc); + +return event; +} +static void tracer_tracing_on (struct trace_array *tr) {if (tr->trace_buffer.buffer)
@@ -795,8 +820,8 @@ int __trace_puts(unsigned long ip, const char *str, int size)local_save_flags (irq_flags); buffer = global_trace.trace_buffer.buffer; - event =trace_buffer_lock_reserve (buffer,TRACE_PRINT , alloc, - irq_flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_PRINT , alloc, + irq_flags, pc);if (!event)return 0 ;
@@ -843,8 +868,8 @@ int __trace_bputs(unsigned long ip, const char *str)local_save_flags (irq_flags); buffer = global_trace.trace_buffer.buffer; - event =trace_buffer_lock_reserve (buffer,TRACE_BPUTS , size, - irq_flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_BPUTS , size, + irq_flags, pc);if (!event)return 0 ;
@@ -1913,29 +1938,13 @@ tracing_generic_entry_update(struct trace_entry *entry, unsigned long flags, }EXPORT_SYMBOL_GPL (tracing_generic_entry_update); -static __always_inline void -trace_event_setup (struct ring_buffer_event *event, -int type,unsigned long flags,int pc) -{ -struct trace_entry *ent =ring_buffer_event_data (event); - -tracing_generic_entry_update (ent, flags, pc); - ent->type = type; -} -struct ring_buffer_event *trace_buffer_lock_reserve (struct ring_buffer *buffer,int type,unsigned long len,unsigned long flags,int pc) { -struct ring_buffer_event *event; - - event =ring_buffer_lock_reserve (buffer, len); -if (event !=NULL ) -trace_event_setup (event, type, flags, pc); - -return event; +return __trace_buffer_lock_reserve (buffer, type, len, flags, pc); } DEFINE_PER_CPU(struct ring_buffer_event *, trace_buffered_event);
@@ -2090,8 +2099,8 @@ trace_event_buffer_lock_reserve(struct ring_buffer **current_rb,this_cpu_dec (trace_buffered_event_cnt); } - entry =trace_buffer_lock_reserve (*current_rb, - type, len, flags, pc); + entry =__trace_buffer_lock_reserve (*current_rb, + type, len, flags, pc);/* * If tracing is off, but we have triggers enabled * we still need to look at the event data. Use the temp_buffer
@@ -2100,8 +2109,8 @@ trace_event_buffer_lock_reserve(struct ring_buffer **current_rb,*/ if (!entry && trace_file->flags &EVENT_FILE_FL_TRIGGER_COND ) { *current_rb = temp_buffer; - entry =trace_buffer_lock_reserve (*current_rb, - type, len, flags, pc); + entry =__trace_buffer_lock_reserve (*current_rb, + type, len, flags, pc); }return entry; }
@@ -2262,8 +2271,8 @@ trace_function(struct trace_array *tr,struct ring_buffer_event *event;struct ftrace_entry *entry; - event =trace_buffer_lock_reserve (buffer,TRACE_FN ,sizeof (*entry), - flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_FN ,sizeof (*entry), + flags, pc);if (!event)return ; entry =ring_buffer_event_data (event);
@@ -2342,8 +2351,8 @@ static void __ftrace_trace_stack(struct ring_buffer *buffer, size *=sizeof (unsigned long ); - event =trace_buffer_lock_reserve (buffer,TRACE_STACK , -sizeof (*entry) + size, flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_STACK , +sizeof (*entry) + size, flags, pc);if (!event) goto out; entry =ring_buffer_event_data (event);
@@ -2444,8 +2453,8 @@ ftrace_trace_userstack(struct ring_buffer *buffer, unsigned long flags, int pc)__this_cpu_inc (user_stack_count); - event =trace_buffer_lock_reserve (buffer,TRACE_USER_STACK , -sizeof (*entry), flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_USER_STACK , +sizeof (*entry), flags, pc);if (!event) goto out_drop_count; entry =ring_buffer_event_data (event);
@@ -2615,8 +2624,8 @@ int trace_vbprintk(unsigned long ip, const char *fmt, va_list args)local_save_flags (flags); size =sizeof (*entry) +sizeof (u32) * len; buffer = tr->trace_buffer.buffer; - event =trace_buffer_lock_reserve (buffer,TRACE_BPRINT , size, - flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_BPRINT , size, + flags, pc);if (!event) goto out; entry =ring_buffer_event_data (event);
@@ -2671,8 +2680,8 @@ __trace_array_vprintk(struct ring_buffer *buffer,local_save_flags (flags); size =sizeof (*entry) + len +1 ; - event =trace_buffer_lock_reserve (buffer,TRACE_PRINT , size, - flags, pc); + event =__trace_buffer_lock_reserve (buffer,TRACE_PRINT , size, + flags, pc);if (!event) goto out; entry =ring_buffer_event_data (event);
@@ -5732,8 +5741,8 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,local_save_flags (irq_flags); size =sizeof (*entry) + cnt +2 ;/* possible \n added */ buffer = tr->trace_buffer.buffer; - event =trace_buffer_lock_reserve (buffer,TRACE_PRINT , size, - irq_flags,preempt_count ()); + event =__trace_buffer_lock_reserve (buffer,TRACE_PRINT , size, + irq_flags,preempt_count ());if (!event) {/* Ring buffer disabled, return as if not open for write */ written = -EBADF ;
@@ -5810,8 +5819,8 @@ tracing_mark_raw_write(struct file *filp, const char __user *ubuf,local_save_flags (irq_flags); size =sizeof (*entry) + cnt; buffer = tr->trace_buffer.buffer; - event =trace_buffer_lock_reserve (buffer,TRACE_RAW_DATA , size, - irq_flags,preempt_count ()); + event =__trace_buffer_lock_reserve (buffer,TRACE_RAW_DATA , size, + irq_flags,preempt_count ());if (!event) {/* Ring buffer disabled, return as if not open for write */ written = -EBADF ;
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 2/8 ring-buffer: Make rb_reserve_next_event() always inlined
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
The function rb_reserved_next_event() is called by two functions:ring_buffer_lock_reserve() and ring_buffer_write(). This is in a very hot path of the tracing code, and it is best that they are not functions. The two callers are basically wrapers for rb_reserver_next_event(). Removing the function calls can save execution time in the hotpath of tracing.
--- kernel/trace/ring_buffer.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/ring_buffer.c +1 -1
@@ -2733,7 +2733,7 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,return event; } -static struct ring_buffer_event * +static __always_inline struct ring_buffer_event *rb_reserve_next_event (struct ring_buffer *buffer,struct ring_buffer_per_cpu *cpu_buffer,unsigned long length)
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 3/8 ring-buffer: Always inline rb_event_data()
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
The rb_event_data() is the fast path of getting the ring buffer data from an event. Externally, ring_buffer_event_data() is used to access this function. But unfortunately, rb_event_data() is not inlined, and calling ring_buffer_event_data() causes that function to be called again. Force rb_event_data() to be inlined to lower the number of operations needed when calling ring_buffer_event_data().
--- kernel/trace/ring_buffer.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/ring_buffer.c +1 -1
@@ -245,7 +245,7 @@ unsigned ring_buffer_event_length(struct ring_buffer_event *event)EXPORT_SYMBOL_GPL (ring_buffer_event_length);/* inline for ring buffer fast paths */ -static void * +static __always_inline void *rb_event_data (struct ring_buffer_event *event) {if (event->type_len ==RINGBUF_TYPE_TIME_EXTEND )
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 4/8 tracing: Make tracepoint_printk a static_key
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
Currently, when tracepoint_printk is set (enabled by the "tp_printk" kernel command line), it causes trace events to print via printk(). This is a very dangerous operation, but is useful for debugging.
The issue is, it's seldom used, but it is always checked even if it's not enabled by the kernel command line. Instead of having this feature called by a branch against a variable, turn that variable into a static key, and this will remove the test and jump.
To simplify things, the functions output_printk() and trace_event_buffer_commit() were moved from trace_events.c to trace.c.
--- include/linux/ftrace.h | 4 +++ kernel/sysctl.c | 2 +- kernel/trace/trace.c | 78 +++++++++++++++++++++++++++++++++++++++++++++ kernel/trace/trace_events.c | 40 ----------------------- 4 files changed, 83 insertions(+), 41 deletions(-)
include/linux/ftrace.h +4 -0
@@ -945,6 +945,10 @@ extern int __disable_trace_on_warning;#define INIT_TRACE_RECURSION .trace_recursion = 0,#endif +int tracepoint_printk_sysctl (struct ctl_table *table,int write, +void __user *buffer,size_t *lenp, +loff_t *ppos); +#else /* CONFIG_TRACING */ static inline void disable_trace_on_warning (void ) { }#endif /* CONFIG_TRACING */
kernel/sysctl.c +1 -1
@@ -634,7 +634,7 @@ static struct ctl_table kern_table[] = { .data = &tracepoint_printk, .maxlen = sizeof(tracepoint_printk), .mode = 0644, - .proc_handler = proc_dointvec, + .proc_handler = tracepoint_printk_sysctl, },#endif #ifdef CONFIG_KEXEC_CORE
kernel/trace/trace.c +78 -0
96 lines not on this page · raw message
kernel/trace/trace_events.c +0 -40
@@ -283,46 +283,6 @@ void *trace_event_buffer_reserve(struct trace_event_buffer *fbuffer, }EXPORT_SYMBOL_GPL (trace_event_buffer_reserve); -static DEFINE_SPINLOCK (tracepoint_iter_lock); - -static void output_printk (struct trace_event_buffer *fbuffer) -{ -struct trace_event_call *event_call; -struct trace_event *event; -unsigned long flags; -struct trace_iterator *iter = tracepoint_print_iter; - -if (!iter) -return ; - - event_call = fbuffer->trace_file->event_call; -if (!event_call || !event_call->event.funcs || - !event_call->event.funcs->trace) -return ; - - event = &fbuffer->trace_file->event_call->event; - -spin_lock_irqsave (&tracepoint_iter_lock, flags); -trace_seq_init (&iter->seq); - iter->ent = fbuffer->entry; - event_call->event.funcs->trace (iter,0 , event); -trace_seq_putc (&iter->seq,0 ); -printk ("%s" , iter->seq.buffer); - -spin_unlock_irqrestore (&tracepoint_iter_lock, flags); -} - -void trace_event_buffer_commit (struct trace_event_buffer *fbuffer) -{ -if (tracepoint_printk) -output_printk (fbuffer); - -event_trigger_unlock_commit (fbuffer->trace_file, fbuffer->buffer, - fbuffer->event, fbuffer->entry, - fbuffer->flags, fbuffer->pc); -} -EXPORT_SYMBOL_GPL (trace_event_buffer_commit); -int trace_event_reg (struct trace_event_call *call,enum trace_reg type,void *data) {
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 5/8 tracing: Make __buffer_unlock_commit() always_inline
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
The function __buffer_unlock_commit() is called in a few places outside of trace.c. But for the most part, it should really be inlined, as it is in the hot path of the trace_events. For the callers outside of trace.c, create a new function trace_buffer_unlock_commit_nostack(), as the reason it was used was to avoid the stack tracing that trace_buffer_unlock_commit() could do.
--- kernel/trace/trace.c | 41 +++++++++++++++++++++++------------- kernel/trace/trace.h | 4 ++-- kernel/trace/trace_branch.c | 2 +- kernel/trace/trace_functions_graph.c | 4 ++-- kernel/trace/trace_hwlat.c | 2 +- 5 files changed, 32 insertions(+), 21 deletions(-)
kernel/trace/trace.c +26 -15
@@ -794,6 +794,22 @@ void tracing_on(void) }EXPORT_SYMBOL_GPL (tracing_on); + +static __always_inline void +__buffer_unlock_commit (struct ring_buffer *buffer,struct ring_buffer_event *event) +{ +__this_cpu_write (trace_cmdline_save, true); + +/* If this is the temp buffer, we need to commit fully */ +if (this_cpu_read (trace_buffered_event) == event) { +/* Length is in event->array[0] */ +ring_buffer_write (buffer, event->array[0 ], &event->array[1 ]); +/* Release the temp buffer */ +this_cpu_dec (trace_buffered_event_cnt); + }else +ring_buffer_unlock_commit (buffer, event); +} +/** * __trace_puts - write a constant string into the trace buffer. * @ip: The address of the caller
@@ -2059,21 +2075,6 @@ void trace_buffered_event_disable(void)preempt_enable (); } -void -__buffer_unlock_commit (struct ring_buffer *buffer,struct ring_buffer_event *event) -{ -__this_cpu_write (trace_cmdline_save, true); - -/* If this is the temp buffer, we need to commit fully */ -if (this_cpu_read (trace_buffered_event) == event) { -/* Length is in event->array[0] */ -ring_buffer_write (buffer, event->array[0 ], &event->array[1 ]); -/* Release the temp buffer */ -this_cpu_dec (trace_buffered_event_cnt); - }else -ring_buffer_unlock_commit (buffer, event); -} -static struct ring_buffer *temp_buffer; struct ring_buffer_event *
@@ -2214,6 +2215,16 @@ void trace_buffer_unlock_commit_regs(struct trace_array *tr,ftrace_trace_userstack (buffer, flags, pc); } +/* +* Similar to trace_buffer_unlock_commit_regs() but do not dump stack. +*/ +void +trace_buffer_unlock_commit_nostack (struct ring_buffer *buffer, +struct ring_buffer_event *event) +{ +__buffer_unlock_commit (buffer, event); +} +static void trace_process_export (struct trace_export *export,struct ring_buffer_event *event)
kernel/trace/trace.h +2 -2
@@ -602,8 +602,8 @@ struct trace_entry *tracing_get_trace_entry(struct trace_array *tr,struct trace_entry *trace_find_next_entry (struct trace_iterator *iter,int *ent_cpu,u64 *ent_ts); -void __buffer_unlock_commit (struct ring_buffer *buffer, -struct ring_buffer_event *event); +void trace_buffer_unlock_commit_nostack (struct ring_buffer *buffer, +struct ring_buffer_event *event);int trace_empty (struct trace_iterator *iter);
kernel/trace/trace_branch.c +1 -1
@@ -81,7 +81,7 @@ probe_likely_condition(struct ftrace_branch_data *f, int val, int expect) entry->correct = val == expect;if (!call_filter_check_discard (call, entry, buffer, event)) -__buffer_unlock_commit (buffer, event); +trace_buffer_unlock_commit_nostack (buffer, event); out: current->trace_recursion &= ~TRACE_BRANCH_BIT ;
kernel/trace/trace_functions_graph.c +2 -2
@@ -358,7 +358,7 @@ int __trace_graph_entry(struct trace_array *tr, entry =ring_buffer_event_data (event); entry->graph_ent = *trace;if (!call_filter_check_discard (call, entry, buffer, event)) -__buffer_unlock_commit (buffer, event); +trace_buffer_unlock_commit_nostack (buffer, event);return 1 ; }
@@ -469,7 +469,7 @@ void __trace_graph_return(struct trace_array *tr, entry =ring_buffer_event_data (event); entry->ret = *trace;if (!call_filter_check_discard (call, entry, buffer, event)) -__buffer_unlock_commit (buffer, event); +trace_buffer_unlock_commit_nostack (buffer, event); }void trace_graph_return (struct ftrace_graph_ret *trace)
kernel/trace/trace_hwlat.c +1 -1
@@ -127,7 +127,7 @@ static void trace_hwlat_sample(struct hwlat_sample *sample) entry->nmi_count = sample->nmi_count;if (!call_filter_check_discard (call, entry, buffer, event)) -__buffer_unlock_commit (buffer, event); +trace_buffer_unlock_commit_nostack (buffer, event); }/* Macros to encapsulate the time capturing infrastructure */
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 6/8 ring-buffer: Force inline of hotpath helper functions
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
There's several small helper functions in ring_buffer.c that are used in the hot path. For some reason, even though they are marked inline, gcc tends not to enforce it. Make sure these functions are always inlined.
--- kernel/trace/ring_buffer.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-)
kernel/trace/ring_buffer.c +8 -8
@@ -1829,48 +1829,48 @@ void ring_buffer_change_overwrite(struct ring_buffer *buffer, int val) }EXPORT_SYMBOL_GPL (ring_buffer_change_overwrite); -static inline void * +static __always_inline void *__rb_data_page_index (struct buffer_data_page *bpage,unsigned index) {return bpage->data + index; } -static inline void *__rb_page_index (struct buffer_page *bpage,unsigned index) +static __always_inline void *__rb_page_index(struct buffer_page *bpage, unsigned index) {return bpage->page->data + index; } -static inline struct ring_buffer_event * +static __always_inline struct ring_buffer_event *rb_reader_event (struct ring_buffer_per_cpu *cpu_buffer) {return __rb_page_index (cpu_buffer->reader_page, cpu_buffer->reader_page->read); } -static inline struct ring_buffer_event * +static __always_inline struct ring_buffer_event *rb_iter_head_event (struct ring_buffer_iter *iter) {return __rb_page_index (iter->head_page, iter->head); } -static inline unsigned rb_page_commit (struct buffer_page *bpage) +static __always_inline unsigned rb_page_commit (struct buffer_page *bpage) {return local_read (&bpage->page->commit); }/* Size is determined by what has been committed */ -static inline unsigned rb_page_size (struct buffer_page *bpage) +static __always_inline unsigned rb_page_size (struct buffer_page *bpage) {return rb_page_commit (bpage); } -static inline unsigned +static __always_inline unsigned rb_commit_index (struct ring_buffer_per_cpu *cpu_buffer) {return rb_page_commit (cpu_buffer->commit_page); } -static inline unsigned +static __always_inline unsigned rb_event_index (struct ring_buffer_event *event) {unsigned long addr = (unsigned long )event;
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 7/8 ring-buffer: Froce rb_update_write_stamp() to be inlined
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
The function rb_update_write_stamp() is in the hotpath of the ring buffer recording. Make sure that it is inlined as well. There's not many places that call it.
--- kernel/trace/ring_buffer.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
kernel/trace/ring_buffer.c +2 -2
@@ -2486,7 +2486,7 @@ static inline void rb_event_discard(struct ring_buffer_event *event) event->time_delta =1 ; } -static inline bool +static __always_inline boolrb_event_is_commit (struct ring_buffer_per_cpu *cpu_buffer,struct ring_buffer_event *event) {
@@ -2500,7 +2500,7 @@ rb_event_is_commit(struct ring_buffer_per_cpu *cpu_buffer,rb_commit_index (cpu_buffer) == index; } -static void +static __always_inline voidrb_update_write_stamp (struct ring_buffer_per_cpu *cpu_buffer,struct ring_buffer_event *event) {
Signature · 1 line
2.10.2
Steven Rostedt
maintainerPATCH 8/8 ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline
In reply to Steven RostedtFrom: "Steven Rostedt (Red Hat)" <[email protected]>
Both rb_end_commit() and rb_set_commit_to_write() are in the fast path of the ring buffer recording. Make sure they are always inlined.
--- kernel/trace/ring_buffer.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
kernel/trace/ring_buffer.c +2 -2
@@ -2386,7 +2386,7 @@ static void rb_start_commit(struct ring_buffer_per_cpu *cpu_buffer)local_inc (&cpu_buffer->commits); } -static void +static __always_inline voidrb_set_commit_to_write (struct ring_buffer_per_cpu *cpu_buffer) {unsigned long max_count;
@@ -2441,7 +2441,7 @@ rb_set_commit_to_write(struct ring_buffer_per_cpu *cpu_buffer) goto again; } -static inline void rb_end_commit (struct ring_buffer_per_cpu *cpu_buffer) +static __always_inline void rb_end_commit(struct ring_buffer_per_cpu *cpu_buffer) {unsigned long commits;
Signature · 1 line
2.10.2