Skip to contentSkip to conversation

ftrace: code consolidation

PATCH Applied Steven Rostedt 3 participants 13 messages Nov 4, 2008

Subsystems (3)
Tracing Tracing ring buffer Tracing OS noise / latency tracers
lore
Share & tools
lore

Steven Rostedt

author maintainer
#0 lore raw

cover ftrace: code consolidation

[ For 2.6.29 ]

The first two patches makes ftrace function calling and other sensitive tracing use a macro to handle preemption disabling. This removes a lot of duplicate code that works on preventing the scheduler from infinite recursion.

The last patch sets an easy way for the user to either use irq disabling or preemption disabing for the function tracer.

Peter Zijlstra noticed a bit of a trace that was not showing up due to lost traces caused by interrupts when the function tracer was running.

Due to the sensitive nature of the function tracer, it can not allow for recursive tracing, so it needs to disable recursion while it records the trace. But this also means that without disabling interrupts, any interrupt that happens while the trace is happening will be lost from the trace itself.

-- Steve

author maintainer
#1 lore raw

PATCH 1/3 ftrace: ftrace_preempt_disable

Parts of the tracer needs to be careful about schedule recursion. If the NEED_RESCHED flag is set, a preempt_enable will call schedule. Inside the schedule function, the NEED_RESCHED flag is cleared.

The problem arises when a trace happens in the schedule function but before NEED_RESCHED is cleared. The race is as follows:

schedule()

Quoted 1 line
Quoted 1 line

tracer called

trace_function()
preempt_disable()
[ record trace ]
preempt_enable() <<- here's the issue.

[check NEED_RESCHED]
schedule()
[ Repeat the above, over and over again ]

The naive approach is simply to use preempt_enable_no_schedule instead. The problem with that approach is that, although we solve the schedule recursion issue, we now might lose a preemption check when not in the schedule function.

trace_function()
preempt_disable()
[ record trace ]
[Interrupt comes in and sets NEED_RESCHED]
preempt_enable_no_resched()
[continue without scheduling]

The way ftrace handles this problem is with the following approach:

	int resched;

	resched = need_resched();
	preempt_disable_notrace();
	[record trace]
	if (resched)
		preempt_enable_no_sched_notrace();
	else
		preempt_enable_notrace();

This may seem like the opposite of what we want. If resched is set then we call the "no_sched" version?? The reason we do this is because if NEED_RESCHED is set before we disable preemption, there's two reasons for that:

1) we are in an atomic code path
2) we are already on our way to the schedule function, and maybe even in the schedule function, but have yet to clear the flag.

Both the above cases we do not want to schedule.

This solution has already been implemented within the ftrace infrastructure. But the problem is that it has been implemented several times. This patch encapsulates this code to two nice functions.

  resched = ftrace_preempt_disable();
  [ record trace]
  ftrace_preempt_enable(resched);

This way the tracers do not need to worry about getting it right.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace.h |   48 ++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 48 insertions(+)
kernel/trace/trace.h +48 -0
Index: linux-tip.git/kernel/trace/trace.h
===================================================================
@@ -419,4 +419,52 @@ enum trace_iterator_flags {
 
 extern struct tracer nop_trace;
 
+/**
+ * ftrace_preempt_disable - disable preemption scheduler safe
+ *
+ * When tracing can happen inside the scheduler, there exists
+ * cases that the tracing might happen before the need_resched
+ * flag is checked. If this happens and the tracer calls
+ * preempt_enable (after a disable), a schedule might take place
+ * causing an infinite recursion.
+ *
+ * To prevent this, we read the need_recshed flag before
+ * disabling preemption. When we want to enable preemption we
+ * check the flag, if it is set, then we call preempt_enable_no_resched.
+ * Otherwise, we call preempt_enable.
+ *
+ * The rational for doing the above is that if need resched is set
+ * and we have yet to reschedule, we are either in an atomic location
+ * (where we do not need to check for scheduling) or we are inside
+ * the scheduler and do not want to resched.
+ */
+static inline int ftrace_preempt_disable(void)
+{
+	int resched;
+
+	resched = need_resched();
+	preempt_disable_notrace();
+
+	return resched;
+}
+
+/**
+ * ftrace_preempt_enable - enable preemption scheduler safe
+ * @resched: the return value from ftrace_preempt_disable
+ *
+ * This is a scheduler safe way to enable preemption and not miss
+ * any preemption checks. The disabled saved the state of preemption.
+ * If resched is set, then we were either inside an atomic or
+ * are inside the scheduler (we would have already scheduled
+ * otherwise). In this case, we do not want to call normal
+ * preempt_enable, but preempt_enable_no_resched instead.
+ */
+static inline void ftrace_preempt_enable(int resched)
+{
+	if (resched)
+		preempt_enable_no_resched_notrace();
+	else
+		preempt_enable_notrace();
+}
+
 #endif /* _LINUX_KERNEL_TRACE_H */
Applied
#2 lore raw

Re: [PATCH 1/3] ftrace: ftrace_preempt_disable

i've applied your 3 patches to tip/tracing/ftrace:

b2a866f: ftrace: function tracer with irqs disabled
182e9f5: ftrace: insert in the ftrace_preempt_disable()/enable() functions 8f0a056: ftrace: introduce ftrace_preempt_disable()/enable()

thanks Steve!

Ingo

author maintainer
#3 lore raw

PATCH 1/1 ftrace: ftrace_preempt_disable comment fix

Impact: comment fixes

Updates to ftrace_preempt_disable comments as recommended to me by Andrew Morton.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace.h |   10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)
kernel/trace/trace.h +5 -5
Index: linux-trace.git/kernel/trace/trace.h
===================================================================
@@ -425,17 +425,17 @@ extern struct tracer nop_trace;
  * ftrace_preempt_disable - disable preemption scheduler safe
  *
  * When tracing can happen inside the scheduler, there exists
- * cases that the tracing might happen before the need_resched
+ * cases where tracing might happen before the need_resched
  * flag is checked. If this happens and the tracer calls
  * preempt_enable (after a disable), a schedule might take place
  * causing an infinite recursion.
  *
  * To prevent this, we read the need_recshed flag before
- * disabling preemption. When we want to enable preemption we
- * check the flag, if it is set, then we call preempt_enable_no_resched.
- * Otherwise, we call preempt_enable.
+ * disabling preemption and store it. When we want to enable preemption
+ * we check the stored flag, if it is set, then we call
+ * preempt_enable_no_resched. Otherwise, we call preempt_enable.
  *
- * The rational for doing the above is that if need resched is set
+ * The rationale for doing the above is that if need resched is set
  * and we have yet to reschedule, we are either in an atomic location
  * (where we do not need to check for scheduling) or we are inside
  * the scheduler and do not want to resched.
author maintainer
#4 lore raw

PATCH v2 1/1 ftrace: ftrace_preempt_disable comment fix

[
Changes since v1:

Fixed "need_recshed" to "need_resched"
]

Impact: comment fixes

Updates to ftrace_preempt_disable comments as recommended by Andrew Morton.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace.h |   12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)
kernel/trace/trace.h +6 -6
Index: linux-trace.git/kernel/trace/trace.h
===================================================================
@@ -425,17 +425,17 @@ extern struct tracer nop_trace;
  * ftrace_preempt_disable - disable preemption scheduler safe
  *
  * When tracing can happen inside the scheduler, there exists
- * cases that the tracing might happen before the need_resched
+ * cases where tracing might happen before the need_resched
  * flag is checked. If this happens and the tracer calls
  * preempt_enable (after a disable), a schedule might take place
  * causing an infinite recursion.
  *
- * To prevent this, we read the need_recshed flag before
- * disabling preemption. When we want to enable preemption we
- * check the flag, if it is set, then we call preempt_enable_no_resched.
- * Otherwise, we call preempt_enable.
+ * To prevent this, we read the need_resched flag before
+ * disabling preemption and store it. When we want to enable preemption
+ * we check the stored flag, if it is set, then we call
+ * preempt_enable_no_resched. Otherwise, we call preempt_enable.
  *
- * The rational for doing the above is that if need resched is set
+ * The rationale for doing the above is that if need resched is set
  * and we have yet to reschedule, we are either in an atomic location
  * (where we do not need to check for scheduling) or we are inside
  * the scheduler and do not want to resched.
author maintainer
#5 lore raw

PATCH v3 1/1 ftrace: ftrace_preempt_disable comment fix

[
Changes since v2:

Andrew pointed out that "need resched" should be "need_resched". He's trying to be more critical than Randy Dunlap. ;-)
]

Impact: comment fixes

Updates to ftrace_preempt_disable comments as recommended by Andrew Morton.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace.h |   12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)
kernel/trace/trace.h +6 -6
Index: linux-trace.git/kernel/trace/trace.h
===================================================================
@@ -425,17 +425,17 @@ extern struct tracer nop_trace;
  * ftrace_preempt_disable - disable preemption scheduler safe
  *
  * When tracing can happen inside the scheduler, there exists
- * cases that the tracing might happen before the need_resched
+ * cases where tracing might happen before the need_resched
  * flag is checked. If this happens and the tracer calls
  * preempt_enable (after a disable), a schedule might take place
  * causing an infinite recursion.
  *
- * To prevent this, we read the need_recshed flag before
- * disabling preemption. When we want to enable preemption we
- * check the flag, if it is set, then we call preempt_enable_no_resched.
- * Otherwise, we call preempt_enable.
+ * To prevent this, we read the need_resched flag before
+ * disabling preemption and store it. When we want to enable preemption
+ * we check the stored flag, if it is set, then we call
+ * preempt_enable_no_resched. Otherwise, we call preempt_enable.
  *
- * The rational for doing the above is that if need resched is set
+ * The rationale for doing the above is that if need_resched is set
  * and we have yet to reschedule, we are either in an atomic location
  * (where we do not need to check for scheduling) or we are inside
  * the scheduler and do not want to resched.
author maintainer
#6 lore raw

PATCH 2/3 ftrace: insert in the ftrace_preempt_disable functions

In reply to Steven Rostedt

This patch replaces the schedule safe preempt disable code with the ftrace_preempt_disable and ftrace_preempt_enable safe functions.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/ring_buffer.c        |   27 +++++++++------------------
 kernel/trace/trace.c              |    8 ++------
 kernel/trace/trace_sched_wakeup.c |   13 ++-----------
 kernel/trace/trace_stack.c        |    8 ++------
 4 files changed, 15 insertions(+), 41 deletions(-)
kernel/trace/ring_buffer.c +9 -18
Index: linux-tip.git/kernel/trace/ring_buffer.c
===================================================================
@@ -16,6 +16,8 @@
 #include <linux/list.h>
 #include <linux/fs.h>
 
+#include "trace.h"
+
 /* Up this if you want to test the TIME_EXTENTS and normalization */
 #define DEBUG_SHIFT 0
 

@@ -1122,8 +1124,7 @@ ring_buffer_lock_reserve(struct ring_buf
 		return NULL;
 
 	/* If we are tracing schedule, we don't want to recurse */
-	resched = need_resched();
-	preempt_disable_notrace();
+	resched = ftrace_preempt_disable();
 
 	cpu = raw_smp_processor_id();
 

@@ -1154,10 +1155,7 @@ ring_buffer_lock_reserve(struct ring_buf
 	return event;
 
  out:
-	if (resched)
-		preempt_enable_notrace();
-	else
-		preempt_enable_notrace();
+	ftrace_preempt_enable(resched);
 	return NULL;
 }
 

@@ -1199,12 +1197,9 @@ int ring_buffer_unlock_commit(struct rin
 	/*
 	 * Only the last preempt count needs to restore preemption.
 	 */
-	if (preempt_count() == 1) {
-		if (per_cpu(rb_need_resched, cpu))
-			preempt_enable_no_resched_notrace();
-		else
-			preempt_enable_notrace();
-	} else
+	if (preempt_count() == 1)
+		ftrace_preempt_enable(per_cpu(rb_need_resched, cpu));
+	else
 		preempt_enable_no_resched_notrace();
 
 	return 0;

@@ -1237,8 +1232,7 @@ int ring_buffer_write(struct ring_buffer
 	if (atomic_read(&buffer->record_disabled))
 		return -EBUSY;
 
-	resched = need_resched();
-	preempt_disable_notrace();
+	resched = ftrace_preempt_disable();
 
 	cpu = raw_smp_processor_id();
 

@@ -1264,10 +1258,7 @@ int ring_buffer_write(struct ring_buffer
 
 	ret = 0;
  out:
-	if (resched)
-		preempt_enable_no_resched_notrace();
-	else
-		preempt_enable_notrace();
+	ftrace_preempt_enable(resched);
 
 	return ret;
 }
kernel/trace/trace.c +2 -6
Index: linux-tip.git/kernel/trace/trace.c
===================================================================
@@ -893,8 +893,7 @@ function_trace_call(unsigned long ip, un
 		return;
 
 	pc = preempt_count();
-	resched = need_resched();
-	preempt_disable_notrace();
+	resched = ftrace_preempt_disable();
 	local_save_flags(flags);
 	cpu = raw_smp_processor_id();
 	data = tr->data[cpu];

@@ -904,10 +903,7 @@ function_trace_call(unsigned long ip, un
 		trace_function(tr, data, ip, parent_ip, flags, pc);
 
 	atomic_dec(&data->disabled);
-	if (resched)
-		preempt_enable_no_resched_notrace();
-	else
-		preempt_enable_notrace();
+	ftrace_preempt_enable(resched);
 }
 
 static struct ftrace_ops trace_ops __read_mostly =
kernel/trace/trace_sched_wakeup.c +2 -11
Index: linux-tip.git/kernel/trace/trace_sched_wakeup.c
===================================================================
@@ -50,8 +50,7 @@ wakeup_tracer_call(unsigned long ip, uns
 		return;
 
 	pc = preempt_count();
-	resched = need_resched();
-	preempt_disable_notrace();
+	resched = ftrace_preempt_disable();
 
 	cpu = raw_smp_processor_id();
 	data = tr->data[cpu];

@@ -81,15 +80,7 @@ wakeup_tracer_call(unsigned long ip, uns
  out:
 	atomic_dec(&data->disabled);
 
-	/*
-	 * To prevent recursion from the scheduler, if the
-	 * resched flag was set before we entered, then
-	 * don't reschedule.
-	 */
-	if (resched)
-		preempt_enable_no_resched_notrace();
-	else
-		preempt_enable_notrace();
+	ftrace_preempt_enable(resched);
 }
 
 static struct ftrace_ops trace_ops __read_mostly =
kernel/trace/trace_stack.c +2 -6
Index: linux-tip.git/kernel/trace/trace_stack.c
===================================================================
@@ -107,8 +107,7 @@ stack_trace_call(unsigned long ip, unsig
 	if (unlikely(!ftrace_enabled || stack_trace_disabled))
 		return;
 
-	resched = need_resched();
-	preempt_disable_notrace();
+	resched = ftrace_preempt_disable();
 
 	cpu = raw_smp_processor_id();
 	/* no atomic needed, we only modify this variable by this cpu */

@@ -120,10 +119,7 @@ stack_trace_call(unsigned long ip, unsig
  out:
 	per_cpu(trace_active, cpu)--;
 	/* prevent recursion in schedule */
-	if (resched)
-		preempt_enable_no_resched_notrace();
-	else
-		preempt_enable_notrace();
+	ftrace_preempt_enable(resched);
 }
 
 static struct ftrace_ops trace_ops __read_mostly =
author maintainer
#7 lore raw

PATCH 3/3 ftrace: function tracer with irqs disabled

In reply to Steven Rostedt

To help with performance, I set the ftracer to not disable interrupts, and only to disable preemption. If an interrupt occurred, it would not be traced, because the function tracer protects itself from recursion. This may be faster, but the trace output might miss some traces.

This patch makes the fuction trace disable interrupts, but it also adds a runtime feature to disable preemption instead. It does this by having two different tracer functions. When the function tracer is enabled, it will check to see which version is requested (irqs disabled or preemption disabled). Then it will use the corresponding function as the tracer.

Irq disabling is the default behaviour, but if the user wants better performance, with the chance of missing traces, then they can choose the preempt disabled version.

Running hackbench 3 times with the irqs disabled and 3 times with the preempt disabled function tracer yielded:

tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510

Average:

   irqs disabled:  43.324           166287462
preempt disabled:  39.079           160300385

preempt is 10.8 percent faster than irqs disabled.

I wrote a patch to count function trace recursion and reran hackbench.

With irq disabled: 1,150 times the function tracer did not trace due to
recursion.
with preempt disabled: 5,117,718 times.

The thousand times with irq disabled could be due to NMIs, or simply a case where it called a function that was not protected by notrace.

But we also see that a large amount of the trace is lost with the preempt version.

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace.c |   40 +++++++++++++++++++++++++++++++++++++++-
 kernel/trace/trace.h |    1 +
 2 files changed, 40 insertions(+), 1 deletion(-)
kernel/trace/trace.c +39 -1
Index: linux-tip.git/kernel/trace/trace.c
===================================================================
@@ -235,6 +235,7 @@ static const char *trace_options[] = {
 	"stacktrace",
 	"sched-tree",
 	"ftrace_printk",
+	"ftrace_preempt",
 	NULL
 };
 

@@ -880,7 +881,7 @@ ftrace_special(unsigned long arg1, unsig
 
 #ifdef CONFIG_FUNCTION_TRACER
 static void
-function_trace_call(unsigned long ip, unsigned long parent_ip)
+function_trace_call_preempt_only(unsigned long ip, unsigned long parent_ip)
 {
 	struct trace_array *tr = &global_trace;
 	struct trace_array_cpu *data;

@@ -906,6 +907,37 @@ function_trace_call(unsigned long ip, un
 	ftrace_preempt_enable(resched);
 }
 
+static void
+function_trace_call(unsigned long ip, unsigned long parent_ip)
+{
+	struct trace_array *tr = &global_trace;
+	struct trace_array_cpu *data;
+	unsigned long flags;
+	long disabled;
+	int cpu;
+	int pc;
+
+	if (unlikely(!ftrace_function_enabled))
+		return;
+
+	/*
+	 * Need to use raw, since this must be called before the
+	 * recursive protection is performed.
+	 */
+	raw_local_irq_save(flags);
+	cpu = raw_smp_processor_id();
+	data = tr->data[cpu];
+	disabled = atomic_inc_return(&data->disabled);
+
+	if (likely(disabled == 1)) {
+		pc = preempt_count();
+		trace_function(tr, data, ip, parent_ip, flags, pc);
+	}
+
+	atomic_dec(&data->disabled);
+	raw_local_irq_restore(flags);
+}
+
 static struct ftrace_ops trace_ops __read_mostly =
 {
 	.func = function_trace_call,

@@ -914,6 +946,12 @@ static struct ftrace_ops trace_ops __rea
 void tracing_start_function_trace(void)
 {
 	ftrace_function_enabled = 0;
+
+	if (trace_flags & TRACE_ITER_PREEMPTONLY)
+		trace_ops.func = function_trace_call_preempt_only;
+	else
+		trace_ops.func = function_trace_call;
+
 	register_ftrace_function(&trace_ops);
 	if (tracer_enabled)
 		ftrace_function_enabled = 1;
kernel/trace/trace.h +1 -0
Index: linux-tip.git/kernel/trace/trace.h
===================================================================
@@ -415,6 +415,7 @@ enum trace_iterator_flags {
 	TRACE_ITER_STACKTRACE		= 0x100,
 	TRACE_ITER_SCHED_TREE		= 0x200,
 	TRACE_ITER_PRINTK		= 0x400,
+	TRACE_ITER_PREEMPTONLY		= 0x800,
 };
 
 extern struct tracer nop_trace;
#8 lore raw

Re: [PATCH 3/3] ftrace: function tracer with irqs disabled

Quoted 9 lines · Steven Rostedt

Running hackbench 3 times with the irqs disabled and 3 times with the preempt disabled function tracer yielded:

tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
Quoted 3 lines
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510

your numbers might be correct, but i found that hackbench is not reliable boot-to-boot - it can easily produce 10% systematic noise or more. (perhaps depending on how the various socket data structures happen to be allocated)

the really conclusive way to test this would be to add a hack that either does preempt disable or irqs disable, depending on a runtime flag - and then observe how hackbench performance reacts to the value of that flag.

note that preempt-disable will also produce less trace entries, especially in very irq-rich workloads. Hence it will be "faster".

Ingo

#9 lore raw

Re: [PATCH 3/3] ftrace: function tracer with irqs disabled

Quoted 11 lines · Ingo Molnar
Quoted 9 lines · Steven Rostedt

Running hackbench 3 times with the irqs disabled and 3 times with the preempt disabled function tracer yielded:

tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
Quoted 6 lines
Quoted 3 lines
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510

your numbers might be correct, but i found that hackbench is not reliable boot-to-boot

I found that, too. But if I kill most background processes before testing, hackbench result looks quite stable.

Quoted 18 lines

- it can easily produce 10% systematic noise or
more. (perhaps depending on how the various socket data structures happen to be allocated)

the really conclusive way to test this would be to add a hack that either does preempt disable or irqs disable, depending on a runtime flag - and then observe how hackbench performance reacts to the value of that flag.

note that preempt-disable will also produce less trace entries, especially in very irq-rich workloads. Hence it will be "faster".

Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

#10 lore raw

Re: [PATCH 3/3] ftrace: function tracer with irqs disabled

In reply to Ingo Molnar
Quoted 20 lines · Ingo Molnar
Quoted 9 lines · Steven Rostedt

Running hackbench 3 times with the irqs disabled and 3 times with the preempt disabled function tracer yielded:

tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
Quoted 3 lines
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510

your numbers might be correct, but i found that hackbench is not reliable boot-to-boot - it can easily produce 10% systematic noise or more. (perhaps depending on how the various socket data structures happen to be allocated)

Quoted 4 lines

the really conclusive way to test this would be to add a hack that either does preempt disable or irqs disable, depending on a runtime flag - and then observe how hackbench performance reacts to the value of that flag.

... which is exactly what your patch implements :-)

Quoted 2 lines

note that preempt-disable will also produce less trace entries, especially in very irq-rich workloads. Hence it will be "faster".

this point still holds. Do we have any good guess about the 'captured trace events per second' rate in the two cases, are they the same?

Ingo

author maintainer
#11 lore raw

Re: [PATCH 3/3] ftrace: function tracer with irqs disabled

Quoted 23 lines · Ingo Molnar
Quoted 20 lines · Ingo Molnar
Quoted 9 lines · Steven Rostedt

Running hackbench 3 times with the irqs disabled and 3 times with the preempt disabled function tracer yielded:

tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
Quoted 3 lines
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510

your numbers might be correct, but i found that hackbench is not reliable boot-to-boot - it can easily produce 10% systematic noise or more. (perhaps depending on how the various socket data structures happen to be allocated)

Quoted 6 lines
Quoted 4 lines

the really conclusive way to test this would be to add a hack that either does preempt disable or irqs disable, depending on a runtime flag - and then observe how hackbench performance reacts to the value of that flag.

... which is exactly what your patch implements :-)

Yep ;-)

Those numbers were done without any reboots in between. I even tried it several times, randomly picking to use irqs_disabled and preempt_disabled, and everytime preempt_disabled was around 39 secs, and irqs disabled was around 43.

Quoted 6 lines
Quoted 3 lines

note that preempt-disable will also produce less trace entries, especially in very irq-rich workloads. Hence it will be "faster".

this point still holds. Do we have any good guess about the 'captured trace events per second' rate in the two cases, are they the same?

If you look at the end of my change log, I printed stats from a patch I added that counted the times that ftrace recursed, but did not record. Those numbers were quite big with preempt_disabled.

Quoted 3 lines
Quoted 3 lines

With irq disabled: 1,150 times the function tracer did not trace due to
recursion.
with preempt disabled: 5,117,718 times.

When we used the preempt disabled version, we lost 5 million traces, as suppose to the irq disabled which was only 1,150 traces lost.

Considering that we had 166,256,704 traces total, that 5 million is only 4% lost of traces. Still quite a lot. But again, this is an extreme, because we are tracing hackbench.

-- Steve

#12 lore raw

Re: [PATCH 3/3] ftrace: function tracer with irqs disabled

Quoted 10 lines · Steven Rostedt
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
tracing type       times            entries recorded
------------      --------          ----------------
irq disabled      43.393            166433066
                  43.282            166172618
                  43.298            166256704
preempt disabled  38.969            159871710
                  38.943            159972935
                  39.325            161056510
Quoted 6 lines

When we used the preempt disabled version, we lost 5 million traces, as suppose to the irq disabled which was only 1,150 traces lost.

Considering that we had 166,256,704 traces total, that 5 million is only 4% lost of traces. Still quite a lot. But again, this is an extreme, because we are tracing hackbench.

there's about 10% difference between the two hackbench results - so the lack of 5% of the traces could make up for about half of that overhead.

anyway, that still leaves the other 5% as the _true_ overhead of IRQ disable.

is there some other workload that does not lose this many trace entries, making it easier to compare irqs-off against preempt-off?

Ingo