tracing: removal of ftrace_preempt_disable

GIT PULL In review Steven Rostedt 3 participants 5 messages Jun 4, 2010 – Jun 8, 2010

Subsystems (4)

Tracing ftrace Tracing ring buffer Tracing OS noise / latency tracers

lore

Share & tools

lore

Steven Rostedt

author maintainer

2010-06-04 01:36 UTC #0 lore raw

Ingo,

This bug has been around for a while, and it only causes missed preemption checks (nothing to crash the kernel). This can wait till 2.6.36.

Please pull the latest tip/perf/core-3 tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core-3

Steven Rostedt (2):
tracing/sched: Make preempt_schedule() notrace
tracing: Remove ftrace_preempt_disable/enable

----

 kernel/sched.c                    |    6 ++--
 kernel/trace/ftrace.c             |    5 +--
 kernel/trace/ring_buffer.c        |   38 ++++++-----------------------
 kernel/trace/trace.c              |    5 +--
 kernel/trace/trace.h              |   48 -------------------------------------
 kernel/trace/trace_clock.c        |    5 +--
 kernel/trace/trace_events.c       |    5 +--
 kernel/trace/trace_functions.c    |    6 ++--
 kernel/trace/trace_sched_wakeup.c |    5 +--
 kernel/trace/trace_stack.c        |    6 ++--
 10 files changed, 27 insertions(+), 102 deletions(-)

Steven Rostedt

author maintainer

2010-06-04 01:36 UTC #1 lore raw

PATCH 1/2 tracing/sched: Make preempt_schedule() notrace

From: Steven Rostedt <[email protected]>

The function tracer code uses ftrace_preempt_disable() to disable preemption instead of normal preempt_disable(). But there's a slight race condition that may cause it to lose a preemption check.

This was made to keep the function tracer from recursing on itself by disabling preemption then having the enable call the function tracer again, causing infinite recursion.

The bug was assumed to happen if the call was just in schedule, but this is incorrect. The bug is caused by preempt_schedule() which is called by preempt_enable(). The calling of preempt_enable() when NEED_RESCHED was set would call preempt_schedule() which would call the function tracer again.

By making the preempt_schedule() and add_preempt_count() notrace then this will prevent the inifinite recursion. This is because the add_preempt_count() would stop the preempt_enable() in the function tracer from calling preempt_schedule() again.

The sub_preempt_count() is also made notrace just to keep it symmetric.

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/sched.c |    6 +++---
 1 files changed, 3 insertions(+), 3 deletions(-)

kernel/sched.c +3 -3

index 15b93f6..cd6787e 100644
@@ -3730,7 +3730,7 @@ int mutex_spin_on_owner(struct mutex *lock, struct thread_info *owner)
  * off of preempt_enable. Kernel preemptions off return from interrupt
  * occur there and call schedule directly.
  */
-asmlinkage void __sched preempt_schedule(void)
+asmlinkage void __sched notrace preempt_schedule(void)
 {
 	struct thread_info *ti = current_thread_info();

@@ -3742,9 +3742,9 @@ asmlinkage void __sched preempt_schedule(void)
 		return;
 
 	do {
-		add_preempt_count(PREEMPT_ACTIVE);
+		add_preempt_count_notrace(PREEMPT_ACTIVE);
 		schedule();
-		sub_preempt_count(PREEMPT_ACTIVE);
+		sub_preempt_count_notrace(PREEMPT_ACTIVE);
 
 		/*
 		 * Check again in case we missed a preemption opportunity

Signature · 1 line

1.7.0

Steven Rostedt

author maintainer

2010-06-04 01:36 UTC #2 lore raw

PATCH 2/2 tracing: Remove ftrace_preempt_disable/enable

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

The ftrace_preempt_disable/enable functions were to address a recursive race caused by the function tracer. The function tracer traces all functions which makes it easily susceptible to recursion. One area was preempt_enable(). This would call the scheduler and the schedulre would call the function tracer and loop. (So was it thought).

The ftrace_preempt_disable/enable was made to protect against recursion inside the scheduler by storing the NEED_RESCHED flag. If it was set before the ftrace_preempt_disable() it would not call schedule on ftrace_preempt_enable(), thinking that if it was set before then it would have already scheduled unless it was already in the scheduler.

This worked fine except in the case of SMP, where another task would set the NEED_RESCHED flag for a task on another CPU, and then kick off an IPI to trigger it. This could cause the NEED_RESCHED to be saved at ftrace_preempt_disable() but the IPI to arrive in the the preempt disabled section. The ftrace_preempt_enable() would not call the scheduler because the flag was already set before entring the section.

This bug would cause a missed preemption check and cause lower latencies.

Investigating further, I found that the recusion caused by the function tracer was not due to schedule(), but due to preempt_schedule(). Now that preempt_schedule is completely annotated with notrace, the recusion no longer is an issue.

Reported-by Thomas Gleixner <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>

---
 kernel/trace/ftrace.c             |    5 +--
 kernel/trace/ring_buffer.c        |   38 ++++++-----------------------
 kernel/trace/trace.c              |    5 +--
 kernel/trace/trace.h              |   48 -------------------------------------
 kernel/trace/trace_clock.c        |    5 +--
 kernel/trace/trace_events.c       |    5 +--
 kernel/trace/trace_functions.c    |    6 ++--
 kernel/trace/trace_sched_wakeup.c |    5 +--
 kernel/trace/trace_stack.c        |    6 ++--
 9 files changed, 24 insertions(+), 99 deletions(-)

kernel/trace/ftrace.c +2 -3

index 6d2cb14..0d88ce9 100644
@@ -1883,7 +1883,6 @@ function_trace_probe_call(unsigned long ip, unsigned long parent_ip)
 	struct hlist_head *hhd;
 	struct hlist_node *n;
 	unsigned long key;
-	int resched;
 
 	key = hash_long(ip, FTRACE_HASH_BITS);

@@ -1897,12 +1896,12 @@ function_trace_probe_call(unsigned long ip, unsigned long parent_ip)
 	 * period. This syncs the hash iteration and freeing of items
 	 * on the hash. rcu_read_lock is too dangerous here.
 	 */
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 	hlist_for_each_entry_rcu(entry, n, hhd, node) {
 		if (entry->ip == ip)
 			entry->ops->func(ip, parent_ip, &entry->data);
 	}
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 }
 
 static struct ftrace_ops trace_probe_ops __read_mostly =

kernel/trace/ring_buffer.c +8 ~~-30~~

index 7f6059c..c3d3cd9 100644
@@ -2234,8 +2234,6 @@ static void trace_recursive_unlock(void)
 
 #endif
 
-static DEFINE_PER_CPU(int, rb_need_resched);
-
 /**
  * ring_buffer_lock_reserve - reserve a part of the buffer
  * @buffer: the ring buffer to reserve from

@@ -2256,13 +2254,13 @@ ring_buffer_lock_reserve(struct ring_buffer *buffer, unsigned long length)
 {
 	struct ring_buffer_per_cpu *cpu_buffer;
 	struct ring_buffer_event *event;
-	int cpu, resched;
+	int cpu;
 
 	if (ring_buffer_flags != RB_BUFFERS_ON)
 		return NULL;
 
 	/* If we are tracing schedule, we don't want to recurse */
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 
 	if (atomic_read(&buffer->record_disabled))
 		goto out_nocheck;

@@ -2287,21 +2285,13 @@ ring_buffer_lock_reserve(struct ring_buffer *buffer, unsigned long length)
 	if (!event)
 		goto out;
 
-	/*
-	 * Need to store resched state on this cpu.
-	 * Only the first needs to.
-	 */
-
-	if (preempt_count() == 1)
-		per_cpu(rb_need_resched, cpu) = resched;
-
 	return event;
 
  out:
 	trace_recursive_unlock();
 
  out_nocheck:
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 	return NULL;
 }
 EXPORT_SYMBOL_GPL(ring_buffer_lock_reserve);

@@ -2347,13 +2337,7 @@ int ring_buffer_unlock_commit(struct ring_buffer *buffer,
 
 	trace_recursive_unlock();
 
-	/*
-	 * Only the last preempt count needs to restore preemption.
-	 */
-	if (preempt_count() == 1)
-		ftrace_preempt_enable(per_cpu(rb_need_resched, cpu));
-	else
-		preempt_enable_no_resched_notrace();
+	preempt_enable_notrace();
 
 	return 0;
 }

@@ -2461,13 +2445,7 @@ void ring_buffer_discard_commit(struct ring_buffer *buffer,
 
 	trace_recursive_unlock();
 
-	/*
-	 * Only the last preempt count needs to restore preemption.
-	 */
-	if (preempt_count() == 1)
-		ftrace_preempt_enable(per_cpu(rb_need_resched, cpu));
-	else
-		preempt_enable_no_resched_notrace();
+	preempt_enable_notrace();
 
 }
 EXPORT_SYMBOL_GPL(ring_buffer_discard_commit);

@@ -2493,12 +2471,12 @@ int ring_buffer_write(struct ring_buffer *buffer,
 	struct ring_buffer_event *event;
 	void *body;
 	int ret = -EBUSY;
-	int cpu, resched;
+	int cpu;
 
 	if (ring_buffer_flags != RB_BUFFERS_ON)
 		return -EBUSY;
 
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 
 	if (atomic_read(&buffer->record_disabled))
 		goto out;

@@ -2528,7 +2506,7 @@ int ring_buffer_write(struct ring_buffer *buffer,
 
 	ret = 0;
  out:
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 
 	return ret;
 }

kernel/trace/trace.c +2 -3

index 55e4851..3572714 100644
@@ -1404,7 +1404,6 @@ int trace_vbprintk(unsigned long ip, const char *fmt, va_list args)
 	struct bprint_entry *entry;
 	unsigned long flags;
 	int disable;
-	int resched;
 	int cpu, len = 0, size, pc;
 
 	if (unlikely(tracing_selftest_running || tracing_disabled))

@@ -1414,7 +1413,7 @@ int trace_vbprintk(unsigned long ip, const char *fmt, va_list args)
 	pause_graph_tracing();
 
 	pc = preempt_count();
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 	cpu = raw_smp_processor_id();
 	data = tr->data[cpu];

@@ -1452,7 +1451,7 @@ out_unlock:
 
 out:
 	atomic_dec_return(&data->disabled);
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 	unpause_graph_tracing();
 
 	return len;

kernel/trace/trace.h +0 ~~-48~~

54 lines not on this page · raw message

kernel/trace/trace_clock.c +2 -3

index 9d589d8..52fda6c 100644
@@ -32,16 +32,15 @@
 u64 notrace trace_clock_local(void)
 {
 	u64 clock;
-	int resched;
 
 	/*
 	 * sched_clock() is an architecture implemented, fast, scalable,
 	 * lockless clock. It is not guaranteed to be coherent across
 	 * CPUs, nor across CPU idle events.
 	 */
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 	clock = sched_clock();
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 
 	return clock;
 }

kernel/trace/trace_events.c +2 -3

index 53cffc0..a594f9a 100644
@@ -1524,12 +1524,11 @@ function_test_events_call(unsigned long ip, unsigned long parent_ip)
 	struct ftrace_entry *entry;
 	unsigned long flags;
 	long disabled;
-	int resched;
 	int cpu;
 	int pc;
 
 	pc = preempt_count();
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 	cpu = raw_smp_processor_id();
 	disabled = atomic_inc_return(&per_cpu(ftrace_test_event_disable, cpu));

@@ -1551,7 +1550,7 @@ function_test_events_call(unsigned long ip, unsigned long parent_ip)
 
  out:
 	atomic_dec(&per_cpu(ftrace_test_event_disable, cpu));
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 }
 
 static struct ftrace_ops trace_ops __initdata  =

kernel/trace/trace_functions.c +3 -3

index b3f3776..16aee4d 100644
@@ -54,14 +54,14 @@ function_trace_call_preempt_only(unsigned long ip, unsigned long parent_ip)
 	struct trace_array_cpu *data;
 	unsigned long flags;
 	long disabled;
-	int cpu, resched;
+	int cpu;
 	int pc;
 
 	if (unlikely(!ftrace_function_enabled))
 		return;
 
 	pc = preempt_count();
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 	local_save_flags(flags);
 	cpu = raw_smp_processor_id();
 	data = tr->data[cpu];

@@ -71,7 +71,7 @@ function_trace_call_preempt_only(unsigned long ip, unsigned long parent_ip)
 		trace_function(tr, ip, parent_ip, flags, pc);
 
 	atomic_dec(&data->disabled);
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 }
 
 static void

kernel/trace/trace_sched_wakeup.c +2 -3

index 0e73bc2..c9fd5bd 100644
@@ -46,7 +46,6 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip)
 	struct trace_array_cpu *data;
 	unsigned long flags;
 	long disabled;
-	int resched;
 	int cpu;
 	int pc;

@@ -54,7 +53,7 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip)
 		return;
 
 	pc = preempt_count();
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 
 	cpu = raw_smp_processor_id();
 	if (cpu != wakeup_current_cpu)

@@ -74,7 +73,7 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip)
  out:
 	atomic_dec(&data->disabled);
  out_enable:
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 }
 
 static struct ftrace_ops trace_ops __read_mostly =

kernel/trace/trace_stack.c +3 -3

index f4bc9b2..056468e 100644
@@ -110,12 +110,12 @@ static inline void check_stack(void)
 static void
 stack_trace_call(unsigned long ip, unsigned long parent_ip)
 {
-	int cpu, resched;
+	int cpu;
 
 	if (unlikely(!ftrace_enabled || stack_trace_disabled))
 		return;
 
-	resched = ftrace_preempt_disable();
+	preempt_disable_notrace();
 
 	cpu = raw_smp_processor_id();
 	/* no atomic needed, we only modify this variable by this cpu */

@@ -127,7 +127,7 @@ stack_trace_call(unsigned long ip, unsigned long parent_ip)
  out:
 	per_cpu(trace_active, cpu)--;
 	/* prevent recursion in schedule */
-	ftrace_preempt_enable(resched);
+	preempt_enable_notrace();
 }
 
 static struct ftrace_ops trace_ops __read_mostly =

Signature · 1 line

1.7.0

Lai Jiangshan

Acked-by on v1 2/2

2010-06-04 06:57 UTC #3 lore raw

Re: [PATCH 2/2] tracing: Remove ftrace_preempt_disable/enable

Quoted 2 lines · Steven Rostedt

From: Steven Rostedt <[email protected]>

Acked-by Lai Jiangshan <[email protected]>

I think we may need to ensure need_resched() notrace:

-static inline int need_resched(void)
+static __always_inline int need_resched(void)

-static inline int test_ti_thread_flag(struct thread_info *ti, int flag) +static __always_inline int test_ti_thread_flag(struct thread_info *ti, int flag)

...

I believe compiler will always inline them, It just looks nicer when use __always_inline.

Ingo Molnar

2010-06-08 17:35 UTC #4 lore raw

In reply to Steven Rostedt

Quoted 18 lines · Steven Rostedt

Ingo,
This bug has been around for a while, and it only causes missed preemption checks (nothing to crash the kernel). This can wait till 2.6.36.
Please pull the latest tip/perf/core-3 tree, which can be found at:
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core-3
Steven Rostedt (2):
tracing/sched: Make preempt_schedule() notrace
tracing: Remove ftrace_preempt_disable/enable
----

Quoted 11 lines

 kernel/sched.c                    |    6 ++--
 kernel/trace/ftrace.c             |    5 +--
 kernel/trace/ring_buffer.c        |   38 ++++++-----------------------
 kernel/trace/trace.c              |    5 +--
 kernel/trace/trace.h              |   48 -------------------------------------
 kernel/trace/trace_clock.c        |    5 +--
 kernel/trace/trace_events.c       |    5 +--
 kernel/trace/trace_functions.c    |    6 ++--
 kernel/trace/trace_sched_wakeup.c |    5 +--
 kernel/trace/trace_stack.c        |    6 ++--
 10 files changed, 27 insertions(+), 102 deletions(-)

Pulled, thanks a lot Steve!

Ingo