linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [for-next][PATCH 0/8] tracing: Some micro optimizations
@ 2016-11-29 15:06 Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 1/8] tracing: Create a always_inlined __trace_buffer_lock_reserve() Steven Rostedt
                   ` (7 more replies)
  0 siblings, 8 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton


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(-)

^ permalink raw reply	[flat|nested] 9+ messages in thread

* [for-next][PATCH 1/8] tracing: Create a always_inlined __trace_buffer_lock_reserve()
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 2/8] ring-buffer: Make rb_reserve_next_event() always inlined Steven Rostedt
                   ` (6 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0001-tracing-Create-a-always_inlined-__trace_buffer_lock_.patch --]
[-- Type: text/plain, Size: 7199 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c | 87 +++++++++++++++++++++++++++++-----------------------
 1 file changed, 48 insertions(+), 39 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index edccdff8a36d..490533726b54 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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;
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 2/8] ring-buffer: Make rb_reserve_next_event() always inlined
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 1/8] tracing: Create a always_inlined __trace_buffer_lock_reserve() Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 3/8] ring-buffer: Always inline rb_event_data() Steven Rostedt
                   ` (5 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0002-ring-buffer-Make-rb_reserve_next_event-always-inline.patch --]
[-- Type: text/plain, Size: 1177 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 9c143739b8d7..1f3580cee6cc 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -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)
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 3/8] ring-buffer: Always inline rb_event_data()
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 1/8] tracing: Create a always_inlined __trace_buffer_lock_reserve() Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 2/8] ring-buffer: Make rb_reserve_next_event() always inlined Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 4/8] tracing: Make tracepoint_printk a static_key Steven Rostedt
                   ` (4 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0003-ring-buffer-Always-inline-rb_event_data.patch --]
[-- Type: text/plain, Size: 1225 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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().

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 1f3580cee6cc..2760aaca6d1b 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -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)
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 4/8] tracing: Make tracepoint_printk a static_key
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
                   ` (2 preceding siblings ...)
  2016-11-29 15:06 ` [for-next][PATCH 3/8] ring-buffer: Always inline rb_event_data() Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 5/8] tracing: Make __buffer_unlock_commit() always_inline Steven Rostedt
                   ` (3 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton

[-- Attachment #1: 0004-tracing-Make-tracepoint_printk-a-static_key.patch --]
[-- Type: text/plain, Size: 6520 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 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(-)

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index b3d34d3e0e7e..8700049fd0e5 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -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 */
diff --git a/kernel/sysctl.c b/kernel/sysctl.c
index 706309f9ed84..6ccc60dfbc7a 100644
--- a/kernel/sysctl.c
+++ b/kernel/sysctl.c
@@ -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
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 490533726b54..725e8b2c453f 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -69,6 +69,7 @@ bool __read_mostly tracing_selftest_disabled;
 /* Pipe tracepoints to printk */
 struct trace_iterator *tracepoint_print_iter;
 int tracepoint_printk;
+static DEFINE_STATIC_KEY_FALSE(tracepoint_printk_key);
 
 /* For tracers that don't implement custom flags */
 static struct tracer_opt dummy_tracer_opt[] = {
@@ -2116,6 +2117,81 @@ trace_event_buffer_lock_reserve(struct ring_buffer **current_rb,
 }
 EXPORT_SYMBOL_GPL(trace_event_buffer_lock_reserve);
 
+static DEFINE_SPINLOCK(tracepoint_iter_lock);
+static DEFINE_MUTEX(tracepoint_printk_mutex);
+
+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;
+
+	/* We should never get here if iter is NULL */
+	if (WARN_ON_ONCE(!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);
+}
+
+int tracepoint_printk_sysctl(struct ctl_table *table, int write,
+			     void __user *buffer, size_t *lenp,
+			     loff_t *ppos)
+{
+	int save_tracepoint_printk;
+	int ret;
+
+	mutex_lock(&tracepoint_printk_mutex);
+	save_tracepoint_printk = tracepoint_printk;
+
+	ret = proc_dointvec(table, write, buffer, lenp, ppos);
+
+	/*
+	 * This will force exiting early, as tracepoint_printk
+	 * is always zero when tracepoint_printk_iter is not allocated
+	 */
+	if (!tracepoint_print_iter)
+		tracepoint_printk = 0;
+
+	if (save_tracepoint_printk == tracepoint_printk)
+		goto out;
+
+	if (tracepoint_printk)
+		static_key_enable(&tracepoint_printk_key.key);
+	else
+		static_key_disable(&tracepoint_printk_key.key);
+
+ out:
+	mutex_unlock(&tracepoint_printk_mutex);
+
+	return ret;
+}
+
+void trace_event_buffer_commit(struct trace_event_buffer *fbuffer)
+{
+	if (static_key_false(&tracepoint_printk_key.key))
+		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);
+
 void trace_buffer_unlock_commit_regs(struct trace_array *tr,
 				     struct ring_buffer *buffer,
 				     struct ring_buffer_event *event,
@@ -7977,6 +8053,8 @@ void __init trace_init(void)
 			kmalloc(sizeof(*tracepoint_print_iter), GFP_KERNEL);
 		if (WARN_ON(!tracepoint_print_iter))
 			tracepoint_printk = 0;
+		else
+			static_key_enable(&tracepoint_printk_key.key);
 	}
 	tracer_alloc_buffers();
 	trace_event_init();
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index ba67ede48822..d35fc2b0d304 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -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)
 {
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 5/8] tracing: Make __buffer_unlock_commit() always_inline
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
                   ` (3 preceding siblings ...)
  2016-11-29 15:06 ` [for-next][PATCH 4/8] tracing: Make tracepoint_printk a static_key Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 6/8] ring-buffer: Force inline of hotpath helper functions Steven Rostedt
                   ` (2 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0005-tracing-Make-__buffer_unlock_commit-always_inline.patch --]
[-- Type: text/plain, Size: 5479 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 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(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 725e8b2c453f..60416bf7c591 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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)
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 9294f8606ade..37602e722336 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -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);
 
diff --git a/kernel/trace/trace_branch.c b/kernel/trace/trace_branch.c
index 3a2a73716a5b..75489de546b6 100644
--- a/kernel/trace/trace_branch.c
+++ b/kernel/trace/trace_branch.c
@@ -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;
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 4e480e870474..8e1a115439fa 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -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)
diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
index b97286c48735..775569ec50d0 100644
--- a/kernel/trace/trace_hwlat.c
+++ b/kernel/trace/trace_hwlat.c
@@ -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 */
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 6/8] ring-buffer: Force inline of hotpath helper functions
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
                   ` (4 preceding siblings ...)
  2016-11-29 15:06 ` [for-next][PATCH 5/8] tracing: Make __buffer_unlock_commit() always_inline Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 7/8] ring-buffer: Froce rb_update_write_stamp() to be inlined Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 8/8] ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline Steven Rostedt
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0006-ring-buffer-Force-inline-of-hotpath-helper-functions.patch --]
[-- Type: text/plain, Size: 2464 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 2760aaca6d1b..04068c0ed927 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -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;
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 7/8] ring-buffer: Froce rb_update_write_stamp() to be inlined
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
                   ` (5 preceding siblings ...)
  2016-11-29 15:06 ` [for-next][PATCH 6/8] ring-buffer: Force inline of hotpath helper functions Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  2016-11-29 15:06 ` [for-next][PATCH 8/8] ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline Steven Rostedt
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0007-ring-buffer-Froce-rb_update_write_stamp-to-be-inline.patch --]
[-- Type: text/plain, Size: 1217 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 04068c0ed927..04579a0c7711 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -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 bool
 rb_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 void
 rb_update_write_stamp(struct ring_buffer_per_cpu *cpu_buffer,
 		      struct ring_buffer_event *event)
 {
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [for-next][PATCH 8/8] ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline
  2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
                   ` (6 preceding siblings ...)
  2016-11-29 15:06 ` [for-next][PATCH 7/8] ring-buffer: Froce rb_update_write_stamp() to be inlined Steven Rostedt
@ 2016-11-29 15:06 ` Steven Rostedt
  7 siblings, 0 replies; 9+ messages in thread
From: Steven Rostedt @ 2016-11-29 15:06 UTC (permalink / raw)
  To: linux-kernel; +Cc: Ingo Molnar, Andrew Morton, Andi Kleen

[-- Attachment #1: 0008-ring-buffer-Force-rb_end_commit-and-rb_set_commit_to.patch --]
[-- Type: text/plain, Size: 1200 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

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.

Link: http://lkml.kernel.org/r/20161121183700.GW26852@two.firstfloor.org

Reported-by: Andi Kleen <andi@firstfloor.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ring_buffer.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 04579a0c7711..f17476f9d7f4 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -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 void
 rb_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;
 
-- 
2.10.2

^ permalink raw reply related	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2016-11-29 15:15 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-11-29 15:06 [for-next][PATCH 0/8] tracing: Some micro optimizations Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 1/8] tracing: Create a always_inlined __trace_buffer_lock_reserve() Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 2/8] ring-buffer: Make rb_reserve_next_event() always inlined Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 3/8] ring-buffer: Always inline rb_event_data() Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 4/8] tracing: Make tracepoint_printk a static_key Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 5/8] tracing: Make __buffer_unlock_commit() always_inline Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 6/8] ring-buffer: Force inline of hotpath helper functions Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 7/8] ring-buffer: Froce rb_update_write_stamp() to be inlined Steven Rostedt
2016-11-29 15:06 ` [for-next][PATCH 8/8] ring-buffer: Force rb_end_commit() and rb_set_commit_to_write() inline Steven Rostedt

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).