ftrace/rcu: Handle unsafe RCU functions and ftrace callbacks

From: "Steven Rostedt (Red Hat)" <[email protected]>

Some ftrace function tracing callbacks use RCU (perf), thus if it gets called from tracing a function outside of the RCU tracking, like in entering or leaving NO_HZ idle/userspace, the RCU read locks in the callback are useless.

As normal function tracing does not use RCU, and function tracing happens to help debug RCU, we do not want to limit all callbacks from tracing these "unsafe" RCU functions. Instead, we create an infrastructure that will let us mark these unsafe RCU functions and we will only allow callbacks that explicitly say they do not use RCU to be called by these functions.

This patch adds the infrastructure to create the hash of functions that are RCU unsafe. This is done with the FTRACE_UNSAFE_RCU() macro. It works like EXPORT_SYMBOL() does. Simply place the macro under the RCU unsafe function:

void func(void)

{
	[...]
}

FTRACE_UNSAFE_RCU(func);

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 include/asm-generic/vmlinux.lds.h |   10 +++
 include/linux/ftrace.h            |   38 +++++++++++
 kernel/trace/ftrace.c             |  135 ++++++++++++++++++++++++++++++++++---
 3 files changed, 174 insertions(+), 9 deletions(-)

include/asm-generic/vmlinux.lds.h +10 -0

index 69732d2..fdfddd2 100644
@@ -93,6 +93,15 @@
 #define MCOUNT_REC()
 #endif
 
+#ifdef CONFIG_FUNCTION_TRACER
+#define FTRACE_UNSAFE_RCU()	. = ALIGN(8);				\
+			VMLINUX_SYMBOL(__start_ftrace_unsafe_rcu) = .;	\
+			*(_ftrace_unsafe_rcu)				\
+			VMLINUX_SYMBOL(__stop_ftrace_unsafe_rcu) = .;
+#else
+#define FTRACE_UNSAFE_RCU()
+#endif
+
 #ifdef CONFIG_TRACE_BRANCH_PROFILING
 #define LIKELY_PROFILE()	VMLINUX_SYMBOL(__start_annotated_branch_profile) = .; \
 				*(_ftrace_annotated_branch)			      \

@@ -479,6 +488,7 @@
 	MEM_DISCARD(init.data)						\
 	KERNEL_CTORS()							\
 	MCOUNT_REC()							\
+	FTRACE_UNSAFE_RCU()						\
 	*(.init.rodata)							\
 	FTRACE_EVENTS()							\
 	TRACE_SYSCALLS()						\

include/linux/ftrace.h +38 -0

index 9f15c00..1d17a82 100644
@@ -92,6 +92,9 @@ typedef void (*ftrace_func_t)(unsigned long ip, unsigned long parent_ip,
  * STUB   - The ftrace_ops is just a place holder.
  * INITIALIZED - The ftrace_ops has already been initialized (first use time
  *            register_ftrace_function() is called, it will initialized the ops)
+ * RCU_SAFE - The callback uses no rcu type locking. This allows the
+ *            callback to be called in locations that RCU is not active.
+ *            (like going into or coming out of idle NO_HZ)
  */
 enum {
 	FTRACE_OPS_FL_ENABLED			= 1 << 0,

@@ -103,6 +106,7 @@ enum {
 	FTRACE_OPS_FL_RECURSION_SAFE		= 1 << 6,
 	FTRACE_OPS_FL_STUB			= 1 << 7,
 	FTRACE_OPS_FL_INITIALIZED		= 1 << 8,
+	FTRACE_OPS_FL_RCU_SAFE			= 1 << 9,
 };
 
 struct ftrace_ops {

@@ -219,6 +223,40 @@ static inline int ftrace_function_local_disabled(struct ftrace_ops *ops)
 extern void ftrace_stub(unsigned long a0, unsigned long a1,
 			struct ftrace_ops *op, struct pt_regs *regs);
 
+/*
+ * In order to speed up boot, save both the name and the
+ * address of the function to find to add to hashes. The
+ * list of function mcount addresses are sorted by the address,
+ * but we still need to use the name to find the actual location
+ * as the mcount call is usually not at the address of the
+ * start of the function.
+ */
+struct ftrace_func_finder {
+	const char		*name;
+	unsigned long		ip;
+};
+
+/*
+ * For functions that are called when RCU is not tracking the CPU
+ * (like for entering or leaving NO_HZ mode, and RCU then ignores
+ * the CPU), they need to be marked with FTRACE_UNSAFE_RCU().
+ * This will prevent all function tracing callbacks from calling
+ * this function unless the callback explicitly states that it
+ * doesn't use RCU with the FTRACE_OPS_FL_RCU_SAFE flag.
+ *
+ * The usage of FTRACE_UNSAFE_RCU() is the same as EXPORT_SYMBOL().
+ * Just place the macro underneath the function that is unsafe.
+ */
+#define FTRACE_UNSAFE_RCU(func) \
+	static struct ftrace_func_finder __ftrace_unsafe_rcu_##func	\
+	 __initdata = {							\
+		.name = #func,						\
+		.ip = (unsigned long)func,				\
+	};							\
+	struct ftrace_func_finder *__ftrace_unsafe_rcu_ptr_##func	\
+		  __attribute__((__section__("_ftrace_unsafe_rcu"))) =	\
+		&__ftrace_unsafe_rcu_##func
+
 #else /* !CONFIG_FUNCTION_TRACER */
 /*
  * (un)register_ftrace_function must be a macro since the ops parameter

kernel/trace/ftrace.c +126 -9

index a6d098c..3750360 100644
@@ -1356,6 +1356,23 @@ ftrace_hash_rec_disable(struct ftrace_ops *ops, int filter_hash);
 static void
 ftrace_hash_rec_enable(struct ftrace_ops *ops, int filter_hash);
 
+static int ftrace_convert_size_to_bits(int size)
+{
+	int bits;
+
+	/*
+	 * Make the hash size about 1/2 the # found
+	 */
+	for (size /= 2; size; size >>= 1)
+		bits++;
+
+	/* Don't allocate too much */
+	if (bits > FTRACE_HASH_MAX_BITS)
+		bits = FTRACE_HASH_MAX_BITS;
+
+	return bits;
+}
+
 static int
 ftrace_hash_move(struct ftrace_ops *ops, int enable,
 		 struct ftrace_hash **dst, struct ftrace_hash *src)

@@ -1388,15 +1405,7 @@ ftrace_hash_move(struct ftrace_ops *ops, int enable,
 		goto out;
 	}
 
-	/*
-	 * Make the hash size about 1/2 the # found
-	 */
-	for (size /= 2; size; size >>= 1)
-		bits++;
-
-	/* Don't allocate too much */
-	if (bits > FTRACE_HASH_MAX_BITS)
-		bits = FTRACE_HASH_MAX_BITS;
+	bits = ftrace_convert_size_to_bits(size);
 
 	ret = -ENOMEM;
 	new_hash = alloc_ftrace_hash(bits);

@@ -1486,6 +1495,74 @@ ftrace_ops_test(struct ftrace_ops *ops, unsigned long ip, void *regs)
 	}
 
 
+static __init int ftrace_find_ip(const void *a, const void *b)
+{
+	const struct dyn_ftrace *key = a;
+	const struct dyn_ftrace *rec = b;
+
+	if (key->ip == rec->ip)
+		return 0;
+
+	if (key->ip < rec->ip) {
+		/* If previous is less than, then this is our func */
+		rec--;
+		if (rec->ip < key->ip)
+			return 0;
+		return -1;
+	}
+
+	/* All else, we are greater */
+	return 1;
+}
+
+/*
+ * Find the mcount caller location given the ip address of the
+ * function that contains it. As the mcount caller is usually
+ * after the mcount itself.
+ *
+ * Done for just core functions at boot.
+ */
+static __init unsigned long ftrace_mcount_from_func(unsigned long ip)
+{
+	struct ftrace_page *pg, *last_pg = NULL;
+	struct dyn_ftrace *rec;
+	struct dyn_ftrace key;
+
+	key.ip = ip;
+
+	for (pg = ftrace_pages_start; pg; last_pg = pg, pg = pg->next) {
+		if (ip >= (pg->records[pg->index - 1].ip + MCOUNT_INSN_SIZE))
+			continue;
+
+		/*
+		 * Do the first record manually, as we need to check
+		 * the previous record from the previous page
+		 */
+		if (ip < pg->records[0].ip) {
+			/* First page? Then we found our record! */
+			if (!last_pg)
+				return pg->records[0].ip;
+
+			rec = &last_pg->records[last_pg->index - 1];
+			if (rec->ip < ip)
+				return pg->records[0].ip;
+
+			/* Not found */
+			return 0;
+		}
+
+		rec = bsearch(&key, pg->records + 1, pg->index - 1,
+			      sizeof(struct dyn_ftrace),
+			      ftrace_find_ip);
+		if (rec)
+			return rec->ip;
+
+		break;
+	}
+
+	return 0;
+}
+
 static int ftrace_cmp_recs(const void *a, const void *b)
 {
 	const struct dyn_ftrace *key = a;

@@ -4211,6 +4288,44 @@ struct notifier_block ftrace_module_exit_nb = {
 	.priority = INT_MIN,	/* Run after anything that can remove kprobes */
 };
 
+extern struct ftrace_func_finder *__start_ftrace_unsafe_rcu[];
+extern struct ftrace_func_finder *__stop_ftrace_unsafe_rcu[];
+
+static struct ftrace_hash *ftrace_unsafe_rcu;
+
+static void __init create_unsafe_rcu_hash(void)
+{
+	struct ftrace_func_finder *finder;
+	struct ftrace_func_finder **p;
+	unsigned long ip;
+	char str[KSYM_SYMBOL_LEN];
+	int count;
+
+	count = __stop_ftrace_unsafe_rcu - __start_ftrace_unsafe_rcu;
+	if (!count)
+		return;
+
+	count = ftrace_convert_size_to_bits(count);
+	ftrace_unsafe_rcu = alloc_ftrace_hash(count);
+
+	for (p = __start_ftrace_unsafe_rcu;
+	     p < __stop_ftrace_unsafe_rcu;
+	     p++) {
+		finder = *p;
+
+		ip = ftrace_mcount_from_func(finder->ip);
+		if (WARN_ON_ONCE(!ip))
+			continue;
+
+		/* Make sure this is our ip */
+		kallsyms_lookup(ip, NULL, NULL, NULL, str);
+		if (WARN_ON_ONCE(strcmp(str, finder->name) != 0))
+			continue;
+
+		add_hash_entry(ftrace_unsafe_rcu, ip);
+	}
+}
+
 extern unsigned long __start_mcount_loc[];
 extern unsigned long __stop_mcount_loc[];
 

@@ -4250,6 +4365,8 @@ void __init ftrace_init(void)
 	if (ret)
 		pr_warning("Failed to register trace ftrace module exit notifier\n");
 
+	create_unsafe_rcu_hash();
+
 	set_ftrace_early_filters();
 
 	return;

Signature · 1 line

1.7.10.4

kernel/trace/ftrace.c +7 -0

index a6d098c..3750360 100644
@@ -1356,6 +1356,23 @@ ftrace_hash_rec_disable(struct ftrace_ops *ops, int filter_hash);
 static void
 ftrace_hash_rec_enable(struct ftrace_ops *ops, int filter_hash);
 
+static int ftrace_convert_size_to_bits(int size)
+{
+	int bits;
+
+	/*
+	 * Make the hash size about 1/2 the # found
+	 */

Quoted 19 lines · On Sat, 31 Aug 2013 01:11:18 -0400 Steven Rostedt <[email protected]> wrote:

kernel/trace/ftrace.c +11 -0

index a6d098c..3750360 100644
@@ -1356,6 +1356,23 @@ ftrace_hash_rec_disable(struct ftrace_ops *ops, int filter_hash);
 static void
 ftrace_hash_rec_enable(struct ftrace_ops *ops, int filter_hash);
 
+static int ftrace_convert_size_to_bits(int size)
+{
+	int bits;
+
+	/*
+	 * Make the hash size about 1/2 the # found
+	 */
+	for (size /= 2; size; size >>= 1)
+		bits++;
+
+	/* Don't allocate too much */

kernel/trace/ftrace.c ftrace_hash_rec_disable(struct ftrace_ops *ops, int filter_hash); · line 1375

Quoted 6 lines

kernel/trace/ftrace.c +6 -0

+	if (bits > FTRACE_HASH_MAX_BITS)
+		bits = FTRACE_HASH_MAX_BITS;
+
+	return bits;
+}
+

Just found this bug. Strange that gcc never gave me a warning :-/

Quoted 1 line

Just found this bug. Strange that gcc never gave me a warning :-/

I can't give gcc too much trouble, as I also didn't give you an uninitialized-variable warning.

I was also chasing down a nasty bug that looked to be a pointer corruption somewhere. Still never found exactly where it happened, but it always happened with the following conditions:

synchronize_sched() was in progress

The ftrace_unsafe_callback() was preempted by an interrupt

lockdep was processing a lock

A crash would happen which had memory corruption involved. But the above seemed always to be in play.

From f8f5d278e272c42349b3cd32485faf426d0c459e Mon Sep 17 00:00:00 2001

From f8f5d278e272c42349b3cd32485faf426d0c459e Mon Sep 17 00:00:00 2001
From: "Steven Rostedt (Red Hat)" <[email protected]>
Date: Tue, 3 Sep 2013 20:47:59 -0400
Subject: [PATCH] ftrace: Print a message when the rcu checker is disabled

Let the user know that the RCU safety checker for function tracing has been disabled. The checker only runs when the user specifically configures it in the kernel, and this is done to search for locations in the kernel that may be unsafe for a function trace callback to use rcu_read_lock()s. But if things like function graph tracing is started, which can live lock the machine when the checker is running, it is disabled. It would be nice if the kernel let the user know that the checker is disabled, and when it is re-enabled again.

As the checker only gets disabled and re-enabled by user actions (starting and stoping the function graph tracer or the irqsoff tracer) it is fine to have a printk display that it is disabled or not.

Suggested-by Paul E. McKenney <[email protected]>

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

---
 kernel/trace/trace_functions.c | 4 ++++
 1 file changed, 4 insertions(+)

kernel/trace/trace_functions.c +4 -0

index 0883069..dd59827 100644
@@ -569,6 +569,8 @@ void ftrace_unsafe_rcu_checker_disable(void)
 	atomic_inc(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
 	smp_wmb();
+	pr_info("Disabled FTRACE RCU checker (%pS)\n",
+		__builtin_return_address(0));
 }
 
 void ftrace_unsafe_rcu_checker_enable(void)

@@ -576,6 +578,8 @@ void ftrace_unsafe_rcu_checker_enable(void)
 	atomic_dec(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
 	smp_wmb();
+	pr_info("Enabled FTRACE RCU checker (%pS)\n",
+		__builtin_return_address(0));
 }
 
 static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

Signature · 1 line

1.8.1.4

Quoted 4 lines · On Tue, 3 Sep 2013 15:18:08 -0700 "Paul E. McKenney"…

Quoted 1 line

Just found this bug. Strange that gcc never gave me a warning :-/

I can't give gcc too much trouble, as I also didn't give you an uninitialized-variable warning.

I was also chasing down a nasty bug that looked to be a pointer corruption somewhere. Still never found exactly where it happened, but it always happened with the following conditions:

synchronize_sched() was in progress

The ftrace_unsafe_callback() was preempted by an interrupt

lockdep was processing a lock

A crash would happen which had memory corruption involved. But the above seemed always to be in play.

Now, I changed the logic from disabling context level recursion to disabling recursion at all. That is, the original code had used a series of bits to test for recursion (via helper functions) that would allow for the callback to be preempted by an interrupt, and then be called again.

The new code sets a per_cpu flag, and will not allow the callback to recurse if it were preempted by an interrupt. No real need to allow for that anyway.

I can go and debug this further, because I'm nervous that lockdep may have some kind of bug that the function tracer can trigger. But I'm not too concerned about it.

Here's the diff of the new code against the previous code.

Paul, can I still keep all your acks and reviewed-bys on this?

-- Steve

kernel/trace/ftrace.c +1 -1

index 310b727..899c8c1 100644
@@ -1373,7 +1373,7 @@ ftrace_hash_rec_enable(struct ftrace_ops *ops, int filter_hash);
 
 static int ftrace_convert_size_to_bits(int size)
 {
-	int bits;
+	int bits = 0;
 
 	/*
 	 * Make the hash size about 1/2 the # found

kernel/trace/trace_functions.c +0 -0

index f5a9031..0883069 100644
@@ -561,16 +561,21 @@ static inline int init_func_cmd_traceon(void)
 

kernel/trace/trace_functions.c +4 -3

 	if (atomic_read(&ftrace_unsafe_rcu_disabled))
 		return;
 
 	preempt_disable_notrace();
 
-	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);
-	if (bit < 0)
+	if (this_cpu_read(ftrace_rcu_running))
 		goto out;
 
 	if (WARN_ONCE(ftrace_rcu_unsafe(ip),

@@ -604,13 +608,15 @@ ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		      (void *)ip))
 		goto out;
 
+	this_cpu_write(ftrace_rcu_running, 1);
 	this_cpu_write(ftrace_rcu_func, ip);
+
 	/* Should trigger a RCU splat if called from unsafe RCU function */
 	rcu_read_lock();
 	rcu_read_unlock();
 	this_cpu_write(ftrace_rcu_func, 0);
 
-	trace_clear_recursion(bit);
+	this_cpu_write(ftrace_rcu_running, 0);
  out:
 	preempt_enable_notrace();
 }

Quoted 1 line · Steven Rostedt

Paul, can I still keep all your acks and reviewed-bys on this?

Yep, but some questions below.

Thanx, Paul

Quoted 26 lines

-- Steve

kernel/trace/ftrace.c +1 -1

index 310b727..899c8c1 100644
@@ -1373,7 +1373,7 @@ ftrace_hash_rec_enable(struct ftrace_ops *ops, int filter_hash);
 
 static int ftrace_convert_size_to_bits(int size)
 {
-	int bits;
+	int bits = 0;
 
 	/*
 	 * Make the hash size about 1/2 the # found

kernel/trace/trace_functions.c +1 -0

index f5a9031..0883069 100644
@@ -561,16 +561,21 @@ static inline int init_func_cmd_traceon(void)
 
 #ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
 
+static DEFINE_PER_CPU(int, ftrace_rcu_running);
 static atomic_t ftrace_unsafe_rcu_disabled;
 

kernel/trace/trace_functions.c static inline int init_func_cmd_traceon(void) · line 571

Quoted 5 lines

kernel/trace/trace_functions.c +2 -0

 void ftrace_unsafe_rcu_checker_disable(void)
 {
 	atomic_inc(&ftrace_unsafe_rcu_disabled);
+	/* Make sure the update is seen immediately */
+	smp_wmb();

	smp_mb__after_atomic_inc()?

kernel/trace/trace_functions.c static inline int init_func_cmd_traceon(void) · line 578

Quoted 8 lines

kernel/trace/trace_functions.c +2 -0

 }
 
 void ftrace_unsafe_rcu_checker_enable(void)
 {
 	atomic_dec(&ftrace_unsafe_rcu_disabled);
+	/* Make sure the update is seen immediately */
+	smp_wmb();

	smp_mb__after_atomic_dec()?

kernel/trace/trace_functions.c static void · line 597

Quoted 12 lines

kernel/trace/trace_functions.c +2 -2

 }
 
 static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Quoted 30 lines

kernel/trace/trace_functions.c +4 -3

 	if (atomic_read(&ftrace_unsafe_rcu_disabled))
 		return;
 
 	preempt_disable_notrace();
 
-	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);
-	if (bit < 0)
+	if (this_cpu_read(ftrace_rcu_running))
 		goto out;
 
 	if (WARN_ONCE(ftrace_rcu_unsafe(ip),

@@ -604,13 +608,15 @@ ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		      (void *)ip))
 		goto out;
 
+	this_cpu_write(ftrace_rcu_running, 1);
 	this_cpu_write(ftrace_rcu_func, ip);
+
 	/* Should trigger a RCU splat if called from unsafe RCU function */
 	rcu_read_lock();
 	rcu_read_unlock();
 	this_cpu_write(ftrace_rcu_func, 0);
 
-	trace_clear_recursion(bit);
+	this_cpu_write(ftrace_rcu_running, 0);
  out:
 	preempt_enable_notrace();
 }

Quoted 7 lines

kernel/trace/trace_functions.c static inline int init_func_cmd_traceon(void) · line 571

Quoted 5 lines

void ftrace_unsafe_rcu_checker_disable(void)
{

kernel/trace/trace_functions.c +2 -0

 	atomic_inc(&ftrace_unsafe_rcu_disabled);
+	/* Make sure the update is seen immediately */
+	smp_wmb();

	smp_mb__after_atomic_inc()?

Yep.

Quoted 10 lines

kernel/trace/trace_functions.c static inline int init_func_cmd_traceon(void) · line 578

Quoted 8 lines

}

void ftrace_unsafe_rcu_checker_enable(void)
{

kernel/trace/trace_functions.c +2 -0

 	atomic_dec(&ftrace_unsafe_rcu_disabled);
+	/* Make sure the update is seen immediately */
+	smp_wmb();

	smp_mb__after_atomic_dec()?

Yep.

Quoted 14 lines

kernel/trace/trace_functions.c static void · line 597

Quoted 12 lines

}

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

kernel/trace/trace_functions.c +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Yep.

I'll update it and restart my tests.

kernel/trace/trace_functions.c static void · line 597

Quoted 9 lines

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

kernel/trace/trace_functions.c +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Quoted 5 lines

kernel/trace/trace_functions.c +0 -0

 	if (atomic_read(&ftrace_unsafe_rcu_disabled))
 		return;
 
 	preempt_disable_notrace();
 

Quoted 12 lines · On Tue, 3 Sep 2013 18:24:04 -0700 "Paul E. McKenney"…

Review static void · line 597

Quoted 9 lines

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

(quoted diff) +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Ah, but this is before an atomic_read(), and not an atomic_inc(), thus the normal smp_rmb() is still required.

Quoted 17 lines · On Tue, 3 Sep 2013 22:01:15 -0400 Steven Rostedt <[email protected]> wrote:

Quoted 12 lines · On Tue, 3 Sep 2013 18:24:04 -0700 "Paul E. McKenney"…

Review static void · line 597

Quoted 9 lines

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

(quoted diff) +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Quoted 3 lines

Ah, but this is before an atomic_read(), and not an atomic_inc(), thus the normal smp_rmb() is still required.

Here's the changes against this one:

kernel/trace/trace_functions.c +2 -2

index cdcf187..9e6902a 100644
@@ -569,14 +569,14 @@ void ftrace_unsafe_rcu_checker_disable(void)
 {
 	atomic_inc(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
-	smp_wmb();
+	smp_mb__after_atomic_inc();
 }
 
 void ftrace_unsafe_rcu_checker_enable(void)
 {
 	atomic_dec(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
-	smp_wmb();
+	smp_mb__after_atomic_dec();
 }
 
 static void

Which is nice, because the smp_mb() are now in the really slow path.

Quoted 50 lines · Steven Rostedt

Quoted 17 lines · On Tue, 3 Sep 2013 22:01:15 -0400 Steven Rostedt <[email protected]> wrote:

Quoted 12 lines · On Tue, 3 Sep 2013 18:24:04 -0700 "Paul E. McKenney"…

Review static void · line 597

Quoted 9 lines

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

(quoted diff) +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Quoted 3 lines

Ah, but this is before an atomic_read(), and not an atomic_inc(), thus the normal smp_rmb() is still required.

Here's the changes against this one:

kernel/trace/trace_functions.c +2 -2

index cdcf187..9e6902a 100644
@@ -569,14 +569,14 @@ void ftrace_unsafe_rcu_checker_disable(void)
 {
 	atomic_inc(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
-	smp_wmb();
+	smp_mb__after_atomic_inc();
 }
 
 void ftrace_unsafe_rcu_checker_enable(void)
 {
 	atomic_dec(&ftrace_unsafe_rcu_disabled);
 	/* Make sure the update is seen immediately */
-	smp_wmb();
+	smp_mb__after_atomic_dec();
 }
 
 static void

Quoted 1 line

Which is nice, because the smp_mb() are now in the really slow path.

Looks good!

But now that I look at it more carefully, including the comments... The smp_mb__after_atomic_dec() isn't going to make the update be seen faster -- instead, it will guarantee that if some other CPU sees this CPU's later write, then that CPU will also see the results of the atomic_dec().

Quoted 12 lines · On Tue, 3 Sep 2013 18:24:04 -0700 "Paul E. McKenney"…

kernel/trace/trace_functions.c static void · line 597

Quoted 9 lines

static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);

kernel/trace/trace_functions.c +2 -2

@@ -588,15 +593,14 @@ static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
-	int bit;
-
+	/* Make sure we see disabled or not first */
+	smp_rmb();

	smp_mb__before_atomic_inc()?

Ah, but this is before an atomic_read(), and not an atomic_inc(), thus the normal smp_rmb() is still required.

-- Steve

Quoted 5 lines

Quoted 5 lines

kernel/trace/trace_functions.c +0 -0

 	if (atomic_read(&ftrace_unsafe_rcu_disabled))
 		return;
 
 	preempt_disable_notrace();
 

From: "Steven Rostedt (Red Hat)" <[email protected]>

For the ftrace_ops that use RCU read locks, and can not be called by unsafe RCU functions (those outside of RCU tracking), have them not update the RCU unsafe function records when they are being registered or unregistered.

The ftrace function records store a counter of all the ftrace_ops callbacks that are hooked to the function the record represents. As unsafe RCU functions do not call callbacks that do not specify that they do not use RCU, do not update those records.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/trace/ftrace.c |   19 +++++++++++++++++--
 1 file changed, 17 insertions(+), 2 deletions(-)

kernel/trace/ftrace.c +17 -2

index 3750360..d61f431 100644
@@ -1168,6 +1168,12 @@ static struct ftrace_page *ftrace_new_pgs;
 static struct ftrace_page	*ftrace_pages_start;
 static struct ftrace_page	*ftrace_pages;
 
+/*
+ * Hash of functions that are not safe to be called by
+ * callbacks that use RCU read locks.
+ */
+static struct ftrace_hash *ftrace_unsafe_rcu;
+
 static bool ftrace_hash_empty(struct ftrace_hash *hash)
 {
 	return !hash || !hash->count;

@@ -1638,6 +1644,7 @@ static void __ftrace_hash_rec_update(struct ftrace_ops *ops,
 {
 	struct ftrace_hash *hash;
 	struct ftrace_hash *other_hash;
+	struct ftrace_hash *rcu_hash;
 	struct ftrace_page *pg;
 	struct dyn_ftrace *rec;
 	int count = 0;

@@ -1647,6 +1654,12 @@ static void __ftrace_hash_rec_update(struct ftrace_ops *ops,
 	if (!(ops->flags & FTRACE_OPS_FL_ENABLED))
 		return;
 
+	/* Ignore rcu unsafe functions unless ops handles them */
+	if (ops->flags & FTRACE_OPS_FL_RCU_SAFE)
+		rcu_hash = NULL;
+	else
+		rcu_hash = ftrace_unsafe_rcu;
+
 	/*
 	 * In the filter_hash case:
 	 *   If the count is zero, we update all records.

@@ -1680,6 +1693,10 @@ static void __ftrace_hash_rec_update(struct ftrace_ops *ops,
 		int in_hash = 0;
 		int match = 0;
 
+		/* Ignore all in the rcu unsafe hash */
+		if (ftrace_lookup_ip(rcu_hash, rec->ip))
+			continue;
+
 		if (all) {
 			/*
 			 * Only the filter_hash affects all records.

@@ -4291,8 +4308,6 @@ struct notifier_block ftrace_module_exit_nb = {
 extern struct ftrace_func_finder *__start_ftrace_unsafe_rcu[];
 extern struct ftrace_func_finder *__stop_ftrace_unsafe_rcu[];
 
-static struct ftrace_hash *ftrace_unsafe_rcu;
-
 static void __init create_unsafe_rcu_hash(void)
 {
 	struct ftrace_func_finder *finder;

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

Since none of the internal ftrace function tracing uses RCU in their callbacks, it is OK to set the global_ops (the one that they all use) to RCU safe.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/trace/ftrace.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

kernel/trace/ftrace.c +3 -1

index d61f431..a45deaa 100644
@@ -1146,7 +1146,9 @@ static struct ftrace_ops global_ops = {
 	.func			= ftrace_stub,
 	.notrace_hash		= EMPTY_HASH,
 	.filter_hash		= EMPTY_HASH,
-	.flags			= FTRACE_OPS_FL_RECURSION_SAFE | FTRACE_OPS_FL_INITIALIZED,
+	.flags			= FTRACE_OPS_FL_RECURSION_SAFE |
+				  FTRACE_OPS_FL_INITIALIZED |
+				  FTRACE_OPS_FL_RCU_SAFE,
 	INIT_REGEX_LOCK(global_ops)
 };
 

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

Since none of the internal ftrace function tracing uses RCU in their callbacks, it is OK to set the global_ops (the one that they all use) to RCU safe.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/trace/ftrace.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

kernel/trace/ftrace.c +3 -1

index d61f431..a45deaa 100644
@@ -1146,7 +1146,9 @@ static struct ftrace_ops global_ops = {
 	.func			= ftrace_stub,
 	.notrace_hash		= EMPTY_HASH,
 	.filter_hash		= EMPTY_HASH,
-	.flags			= FTRACE_OPS_FL_RECURSION_SAFE | FTRACE_OPS_FL_INITIALIZED,
+	.flags			= FTRACE_OPS_FL_RECURSION_SAFE |
+				  FTRACE_OPS_FL_INITIALIZED |
+				  FTRACE_OPS_FL_RCU_SAFE,
 	INIT_REGEX_LOCK(global_ops)
 };
 

Signature · 1 line

1.7.10.4

Quoted 6 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

Since none of the internal ftrace function tracing uses RCU in their callbacks, it is OK to set the global_ops (the one that they all use) to RCU safe.

Quoted 3 lines

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

Acked-by Paul E. McKenney <[email protected]>

Quoted 24 lines

---
 kernel/trace/ftrace.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

kernel/trace/ftrace.c +3 -1

index d61f431..a45deaa 100644
@@ -1146,7 +1146,9 @@ static struct ftrace_ops global_ops = {
 	.func			= ftrace_stub,
 	.notrace_hash		= EMPTY_HASH,
 	.filter_hash		= EMPTY_HASH,
-	.flags			= FTRACE_OPS_FL_RECURSION_SAFE | FTRACE_OPS_FL_INITIALIZED,
+	.flags			= FTRACE_OPS_FL_RECURSION_SAFE |
+				  FTRACE_OPS_FL_INITIALIZED |
+				  FTRACE_OPS_FL_RCU_SAFE,
 	INIT_REGEX_LOCK(global_ops)
 };
 

Signature · 1 line

1.7.10.4

Quoted 7 lines · On Sat, 31 Aug 2013 12:44:31 -0700 "Paul E. McKenney"…

Quoted 6 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

Since none of the internal ftrace function tracing uses RCU in their callbacks, it is OK to set the global_ops (the one that they all use) to RCU safe.

Quoted 5 lines

Quoted 3 lines

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

Acked-by Paul E. McKenney <[email protected]>

You must have liked this patch so much... that you acked it twice ;-)

-- Steve

Quoted 24 lines

Quoted 24 lines

---
 kernel/trace/ftrace.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

kernel/trace/ftrace.c +3 -1

index d61f431..a45deaa 100644
@@ -1146,7 +1146,9 @@ static struct ftrace_ops global_ops = {
 	.func			= ftrace_stub,
 	.notrace_hash		= EMPTY_HASH,
 	.filter_hash		= EMPTY_HASH,
-	.flags			= FTRACE_OPS_FL_RECURSION_SAFE | FTRACE_OPS_FL_INITIALIZED,
+	.flags			= FTRACE_OPS_FL_RECURSION_SAFE |
+				  FTRACE_OPS_FL_INITIALIZED |
+				  FTRACE_OPS_FL_RCU_SAFE,
 	INIT_REGEX_LOCK(global_ops)
 };
 

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

When more than one ftrace_ops is registered, the list function is is used to call all registered functions. It uses the filter and notrace hashes from the ftrace_ops to determine if the corresponding callback should be called or not.

Currently, it does not take into account for RCU unsafe functions. If multiple functions are registered, and an RCU safe callback is used on a RCU unsafe function, and the RCU unsafe callback says to trace all functions, it will end up tracing this RCU unsafe function and still suffer the problems when using RCU when RCU tracing is off.

Add a test to the multiple ops list function to test if the ops in question can use an RCU unsafe function or not, and if the function being traced happens to be an RCU unsafe function.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/trace/ftrace.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

kernel/trace/ftrace.c +3 -1

index a45deaa..06504b2 100644
@@ -1480,7 +1480,9 @@ ftrace_ops_test(struct ftrace_ops *ops, unsigned long ip, void *regs)
 	if ((ftrace_hash_empty(filter_hash) ||
 	     ftrace_lookup_ip(filter_hash, ip)) &&
 	    (ftrace_hash_empty(notrace_hash) ||
-	     !ftrace_lookup_ip(notrace_hash, ip)))
+	     !ftrace_lookup_ip(notrace_hash, ip)) &&
+	    (ops->flags & FTRACE_OPS_FL_RCU_SAFE ||
+	     !ftrace_lookup_ip(ftrace_unsafe_rcu, ip)))
 		ret = 1;
 	else
 		ret = 0;

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

As available_filter_functions file displays functions that are generally available for tracing, do not show the ones that are RCU unsafe. Otherwise it may be confusing for perf users to see these functions in this file but not be able to trace them.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 include/linux/ftrace.h |    1 +
 kernel/trace/ftrace.c  |    6 +++++-
 2 files changed, 6 insertions(+), 1 deletion(-)

include/linux/ftrace.h +1 -0

index 1d17a82..4709264 100644
@@ -411,6 +411,7 @@ enum {
 	FTRACE_ITER_DO_HASH	= (1 << 3),
 	FTRACE_ITER_HASH	= (1 << 4),
 	FTRACE_ITER_ENABLED	= (1 << 5),
+	FTRACE_ITER_NO_UNSAFE	= (1 << 6),
 };
 
 void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +0 -0

index 06504b2..be87ac9 100644

kernel/trace/ftrace.c +3 -0

+		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
+		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 
 			rec = NULL;
 			goto retry;

@@ -2773,6 +2776,7 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
 	if (iter) {
 		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_NO_UNSAFE;
 		iter->ops = &global_ops;
 	}
 

Signature · 1 line

1.7.10.4

Quoted 8 lines

void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +0 -0

index 06504b2..be87ac9 100644
@@ -2645,7 +2645,10 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||
 

kernel/trace/ftrace.c t_next(struct seq_file *m, void *v, loff_t *pos) · line 2649

Quoted 4 lines

kernel/trace/ftrace.c +2 -1

 		    ((iter->flags & FTRACE_ITER_ENABLED) &&
-		     !(rec->flags & FTRACE_FL_ENABLED))) {
+		     !(rec->flags & FTRACE_FL_ENABLED)) ||
+

OK, I'll bite... Why the blank line?

Thanx, Paul

Quoted 17 lines

kernel/trace/ftrace.c +3 -0

+		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
+		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 
 			rec = NULL;
 			goto retry;

@@ -2773,6 +2776,7 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
 	if (iter) {
 		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_NO_UNSAFE;
 		iter->ops = &global_ops;
 	}
 

Signature · 1 line

1.7.10.4

Quoted 8 lines · Paul E. McKenney

Quoted 8 lines

void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +0 -0

index 06504b2..be87ac9 100644
@@ -2645,7 +2645,10 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||
 

Quoted 6 lines

kernel/trace/ftrace.c t_next(struct seq_file *m, void *v, loff_t *pos) · line 2649

Quoted 4 lines

kernel/trace/ftrace.c +2 -1

 		    ((iter->flags & FTRACE_ITER_ENABLED) &&
-		     !(rec->flags & FTRACE_FL_ENABLED))) {
+		     !(rec->flags & FTRACE_FL_ENABLED)) ||
+

OK, I'll bite... Why the blank line?

For readability. Here's the full if statement:

                if (((iter->flags & FTRACE_ITER_FILTER) &&
                     !(ftrace_lookup_ip(ops->filter_hash, rec->ip))) ||

                    ((iter->flags & FTRACE_ITER_NOTRACE) &&
                     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||

                    ((iter->flags & FTRACE_ITER_ENABLED) &&
                     !(rec->flags & FTRACE_FL_ENABLED)) ||

                    ((iter->flags & FTRACE_ITER_UNSAFE_ONLY) &&
                     !ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip)) ||

                    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
                     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {

They are grouped in pairs.

-- Steve

Quoted 20 lines

Thanx, Paul

Quoted 17 lines

kernel/trace/ftrace.c +3 -0

+		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
+		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 
 			rec = NULL;
 			goto retry;

@@ -2773,6 +2776,7 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
 	if (iter) {
 		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_NO_UNSAFE;
 		iter->ops = &global_ops;
 	}
 

Signature · 1 line

1.7.10.4

Quoted 31 lines · Steven Rostedt

Quoted 8 lines · Paul E. McKenney

Quoted 8 lines

void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +0 -0

index 06504b2..be87ac9 100644
@@ -2645,7 +2645,10 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||
 

Quoted 6 lines

kernel/trace/ftrace.c t_next(struct seq_file *m, void *v, loff_t *pos) · line 2649

Quoted 4 lines

kernel/trace/ftrace.c +2 -1

 		    ((iter->flags & FTRACE_ITER_ENABLED) &&
-		     !(rec->flags & FTRACE_FL_ENABLED))) {
+		     !(rec->flags & FTRACE_FL_ENABLED)) ||
+

OK, I'll bite... Why the blank line?

For readability. Here's the full if statement:

                if (((iter->flags & FTRACE_ITER_FILTER) &&
                     !(ftrace_lookup_ip(ops->filter_hash, rec->ip))) ||

                    ((iter->flags & FTRACE_ITER_NOTRACE) &&
                     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||

                    ((iter->flags & FTRACE_ITER_ENABLED) &&
                     !(rec->flags & FTRACE_FL_ENABLED)) ||

                    ((iter->flags & FTRACE_ITER_UNSAFE_ONLY) &&
                     !ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip)) ||

Quoted 5 lines

                    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
                     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {

They are grouped in pairs.

Fair enough!

Thanx, Paul

Quoted 24 lines

-- Steve

Quoted 20 lines

Thanx, Paul

Quoted 17 lines

kernel/trace/ftrace.c +3 -0

+		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
+		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 
 			rec = NULL;
 			goto retry;

@@ -2773,6 +2776,7 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
 	if (iter) {
 		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_NO_UNSAFE;
 		iter->ops = &global_ops;
 	}
 

Signature · 1 line

1.7.10.4

Quoted 36 lines · On Sat, 31 Aug 2013 13:54:30 -0700 "Paul E. McKenney"…

Quoted 35 lines · Steven Rostedt

Quoted 8 lines · Paul E. McKenney

Quoted 8 lines

void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +0 -0

index 06504b2..be87ac9 100644
@@ -2645,7 +2645,10 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||
 

Quoted 6 lines

kernel/trace/ftrace.c t_next(struct seq_file *m, void *v, loff_t *pos) · line 2649

Quoted 4 lines

kernel/trace/ftrace.c +2 -1

 		    ((iter->flags & FTRACE_ITER_ENABLED) &&
-		     !(rec->flags & FTRACE_FL_ENABLED))) {
+		     !(rec->flags & FTRACE_FL_ENABLED)) ||
+

OK, I'll bite... Why the blank line?

For readability. Here's the full if statement:

                if (((iter->flags & FTRACE_ITER_FILTER) &&
                     !(ftrace_lookup_ip(ops->filter_hash, rec->ip))) ||

                    ((iter->flags & FTRACE_ITER_NOTRACE) &&
                     !ftrace_lookup_ip(ops->notrace_hash, rec->ip)) ||

                    ((iter->flags & FTRACE_ITER_ENABLED) &&
                     !(rec->flags & FTRACE_FL_ENABLED)) ||

                    ((iter->flags & FTRACE_ITER_UNSAFE_ONLY) &&
                     !ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip)) ||

                    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
                     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {

Quoted 3 lines

Quoted 1 line

They are grouped in pairs.

Fair enough!

Can I take this as an Acked-by?

-- Steve

Quoted 27 lines

Thanx, Paul

Quoted 24 lines

-- Steve

Quoted 20 lines

Thanx, Paul

Quoted 17 lines

kernel/trace/ftrace.c +3 -0

+		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
+		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 
 			rec = NULL;
 			goto retry;

@@ -2773,6 +2776,7 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
 	if (iter) {
 		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_NO_UNSAFE;
 		iter->ops = &global_ops;
 	}
 

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

Since the RCU unsafe functions are no longer displayed by the available_filter_functions, we still need a way to see these functions in order to trace them. Create a new file that lists the functions that were declared RCU unsafe.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 include/linux/ftrace.h |    1 +
 kernel/trace/ftrace.c  |   31 +++++++++++++++++++++++++++++++
 2 files changed, 32 insertions(+)

include/linux/ftrace.h +1 -0

index 4709264..4752764 100644
@@ -412,6 +412,7 @@ enum {
 	FTRACE_ITER_HASH	= (1 << 4),
 	FTRACE_ITER_ENABLED	= (1 << 5),
 	FTRACE_ITER_NO_UNSAFE	= (1 << 6),
+	FTRACE_ITER_UNSAFE_ONLY	= (1 << 7),
 };
 
 void arch_ftrace_update_code(int command);

kernel/trace/ftrace.c +31 -0

index be87ac9..a3e4b71 100644
@@ -2647,6 +2647,9 @@ t_next(struct seq_file *m, void *v, loff_t *pos)
 		    ((iter->flags & FTRACE_ITER_ENABLED) &&
 		     !(rec->flags & FTRACE_FL_ENABLED)) ||
 
+		    ((iter->flags & FTRACE_ITER_UNSAFE_ONLY) &&
+		     !ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip)) ||
+
 		    ((iter->flags & FTRACE_ITER_NO_UNSAFE) &&
 		     ftrace_lookup_ip(ftrace_unsafe_rcu, rec->ip))) {
 

@@ -2784,6 +2787,24 @@ ftrace_avail_open(struct inode *inode, struct file *file)
 }
 
 static int
+ftrace_rcu_unsafe_open(struct inode *inode, struct file *file)
+{
+	struct ftrace_iterator *iter;
+
+	if (unlikely(ftrace_disabled))
+		return -ENODEV;
+
+	iter = __seq_open_private(file, &show_ftrace_seq_ops, sizeof(*iter));
+	if (iter) {
+		iter->pg = ftrace_pages_start;
+		iter->flags = FTRACE_ITER_UNSAFE_ONLY;
+		iter->ops = &global_ops;
+	}
+
+	return iter ? 0 : -ENOMEM;
+}
+
+static int
 ftrace_enabled_open(struct inode *inode, struct file *file)
 {
 	struct ftrace_iterator *iter;

@@ -3835,6 +3856,13 @@ static const struct file_operations ftrace_avail_fops = {
 	.release = seq_release_private,
 };
 
+static const struct file_operations ftrace_rcu_unsafe_fops = {
+	.open = ftrace_rcu_unsafe_open,
+	.read = seq_read,
+	.llseek = seq_lseek,
+	.release = seq_release_private,
+};
+
 static const struct file_operations ftrace_enabled_fops = {
 	.open = ftrace_enabled_open,
 	.read = seq_read,

@@ -4071,6 +4099,9 @@ static __init int ftrace_init_dyn_debugfs(struct dentry *d_tracer)
 	trace_create_file("available_filter_functions", 0444,
 			d_tracer, NULL, &ftrace_avail_fops);
 
+	trace_create_file("rcu_unsafe_filter_functions", 0444,
+			d_tracer, NULL, &ftrace_rcu_unsafe_fops);
+
 	trace_create_file("enabled_functions", 0444,
 			d_tracer, NULL, &ftrace_enabled_fops);
 

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

Add a boot time start up test that has a RCU safe ftrace_ops as well as an unsafe one. Make sure the RCU safe ops can trace RCU unsafe functions while the unsafe ftrace_ops can not.

Cc Jiri Olsa <[email protected]>

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/trace/trace.h                  |    2 +
 kernel/trace/trace_selftest.c         |   94 +++++++++++++++++++++++++++++++++
 kernel/trace/trace_selftest_dynamic.c |    7 +++
 3 files changed, 103 insertions(+)

kernel/trace/trace.h +2 -0

index 502fed7..3578be6 100644
@@ -648,6 +648,8 @@ extern unsigned long ftrace_update_tot_cnt;
 extern int DYN_FTRACE_TEST_NAME(void);
 #define DYN_FTRACE_TEST_NAME2 trace_selftest_dynamic_test_func2
 extern int DYN_FTRACE_TEST_NAME2(void);
+#define DYN_FTRACE_TEST_RCU_UNSAFE trace_selftest_dynamic_test_rcu_unsafe
+extern int DYN_FTRACE_TEST_RCU_UNSAFE(void);
 
 extern bool ring_buffer_expanded;
 extern bool tracing_selftest_disabled;

kernel/trace/trace_selftest.c +94 -0

index a7329b7..eeacb47 100644
@@ -185,6 +185,97 @@ static void reset_counts(void)
 	trace_selftest_test_dyn_cnt = 0;
 }
 
+static struct ftrace_ops ftrace_rcu_safe_ops = {
+	.func		= trace_selftest_test_probe1_func,
+	.flags		= FTRACE_OPS_FL_RECURSION_SAFE | FTRACE_OPS_FL_RCU_SAFE,
+};
+
+static struct ftrace_ops ftrace_rcu_unsafe_ops = {
+	.func		= trace_selftest_test_probe2_func,
+	.flags		= FTRACE_OPS_FL_RECURSION_SAFE,
+};
+
+static int test_rcu_safe_unsafe(void)
+{
+	int save_ftrace_enabled = ftrace_enabled;
+	char *func_name;
+	int len;
+	int ret = 0;
+
+	printk(KERN_CONT "PASSED\n");
+	pr_info("Testing ftrace rcu safe unsafe: ");
+
+	ftrace_enabled = 1;
+
+	trace_selftest_test_probe1_cnt = 0;
+	trace_selftest_test_probe2_cnt = 0;
+
+	func_name = "*" __stringify(DYN_FTRACE_TEST_RCU_UNSAFE);
+	len = strlen(func_name);
+
+	ftrace_set_filter(&ftrace_rcu_safe_ops, func_name, len, 1);
+	ftrace_set_filter(&ftrace_rcu_unsafe_ops, func_name, len, 1);
+
+	/* Do single registrations first */
+	register_ftrace_function(&ftrace_rcu_safe_ops);
+
+	DYN_FTRACE_TEST_RCU_UNSAFE();
+
+	unregister_ftrace_function(&ftrace_rcu_safe_ops);
+
+	if (trace_selftest_test_probe1_cnt != 1) {
+		printk(KERN_CONT "rcu_safe expected 1 call but had %d ",
+		       trace_selftest_test_probe1_cnt);
+		goto out;
+	}
+
+	register_ftrace_function(&ftrace_rcu_unsafe_ops);
+
+	DYN_FTRACE_TEST_RCU_UNSAFE();
+
+	unregister_ftrace_function(&ftrace_rcu_unsafe_ops);
+
+	if (trace_selftest_test_probe2_cnt != 0) {
+		printk(KERN_CONT "rcu_safe expected 0 calls but had %d ",
+		       trace_selftest_test_probe2_cnt);
+		goto out;
+	}
+
+	/* Run both together, which uses the list op */
+
+	trace_selftest_test_probe1_cnt = 0;
+	trace_selftest_test_probe2_cnt = 0;
+
+	register_ftrace_function(&ftrace_rcu_safe_ops);
+	register_ftrace_function(&ftrace_rcu_unsafe_ops);
+
+	DYN_FTRACE_TEST_RCU_UNSAFE();
+	DYN_FTRACE_TEST_RCU_UNSAFE();
+	DYN_FTRACE_TEST_RCU_UNSAFE();
+
+	unregister_ftrace_function(&ftrace_rcu_unsafe_ops);
+	unregister_ftrace_function(&ftrace_rcu_safe_ops);
+
+
+	if (trace_selftest_test_probe1_cnt != 3) {
+		printk(KERN_CONT "rcu_safe expected 3 calls but had %d ",
+		       trace_selftest_test_probe1_cnt);
+		goto out;
+	}
+
+	if (trace_selftest_test_probe2_cnt != 0) {
+		printk(KERN_CONT "rcu_safe expected 0 calls but had %d ",
+		       trace_selftest_test_probe2_cnt);
+		goto out;
+	}
+
+	ret = 0;
+ out:
+	ftrace_enabled = save_ftrace_enabled;
+
+	return ret;
+}
+
 static int trace_selftest_ops(int cnt)
 {
 	int save_ftrace_enabled = ftrace_enabled;

@@ -401,6 +492,9 @@ int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
 	if (!ret)
 		ret = trace_selftest_ops(2);
 
+	if (!ret)
+		ret = test_rcu_safe_unsafe();
+
 	return ret;
 }
 

kernel/trace/trace_selftest_dynamic.c +7 -0

index b4c475a..5eefa56 100644
@@ -11,3 +11,10 @@ int DYN_FTRACE_TEST_NAME2(void)
 	/* used to call mcount */
 	return 0;
 }
+
+int trace_selftest_dynamic_test_rcu_unsafe(void)
+{
+	/* used to call mcount */
+	return 0;
+}
+FTRACE_UNSAFE_RCU(trace_selftest_dynamic_test_rcu_unsafe);

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

The function debug_lockdep_rcu_enabled() is part of the RCU lockdep debugging, and is called very frequently. I found that if I enable a lot of debugging and run the function graph tracer, this function can cause a live lock of the system.

We don't usually trace lockdep infrastructure, no need to trace this either.

Cc Paul E. McKenney <[email protected]>

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

---
 kernel/rcupdate.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

kernel/rcupdate.c +1 -1

index cce6ba8..4f20c6c 100644
@@ -122,7 +122,7 @@ struct lockdep_map rcu_sched_lock_map =
 	STATIC_LOCKDEP_MAP_INIT("rcu_read_lock_sched", &rcu_sched_lock_key);
 EXPORT_SYMBOL_GPL(rcu_sched_lock_map);
 
-int debug_lockdep_rcu_enabled(void)
+int notrace debug_lockdep_rcu_enabled(void)
 {
 	return rcu_scheduler_active && debug_locks &&
 	       current->lockdep_recursion == 0;

Signature · 1 line

1.7.10.4

Quoted 10 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

The function debug_lockdep_rcu_enabled() is part of the RCU lockdep debugging, and is called very frequently. I found that if I enable a lot of debugging and run the function graph tracer, this function can cause a live lock of the system.

We don't usually trace lockdep infrastructure, no need to trace this either.

Quoted 2 lines

Cc Paul E. McKenney <[email protected]>

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

Reviewed-by Paul E. McKenney <[email protected]>

Or I can just take it, if you would rather. (If so, 3.12 or 3.13?)

From: "Steven Rostedt (Red Hat)" <[email protected]>

Knowing what functions are not safe to be traced by callbacks that use RCU read locks, is not easy to figure out. By adding a function tracer callback that is set as a non RCU safe callback that also uses rcu_read_lock() and enables PROVE_RCU, it can be used to find locations in the kernel that need to be tagged with FTRACE_UNSAFE_RCU().

On boot up, this callback gets registered so that all functions are being traced, and there's no way to turn this off. In the future we can make this enabled or disabled at run time, but for now it's only used for debugging and should not be enabled by normal users.

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

---
 kernel/trace/Kconfig           |   22 +++++++++++++++++++
 kernel/trace/ftrace.c          |   12 ++++++++++
 kernel/trace/trace.h           |    3 +++
 kernel/trace/trace_functions.c |   47 +++++++++++++++++++++++++++++++++++++++-
 4 files changed, 83 insertions(+), 1 deletion(-)

kernel/trace/Kconfig +22 -0

index 015f85a..907b497 100644
@@ -489,6 +489,28 @@ config FTRACE_MCOUNT_RECORD
 config FTRACE_SELFTEST
 	bool
 
+config FTRACE_UNSAFE_RCU_CHECKER
+        bool "Trace for unsafe RCU callers"
+	depends on DYNAMIC_FTRACE
+	depends on PROVE_LOCKING
+	select PROVE_RCU
+	help
+	 Some function tracing callbacks use RCU read lock (namely perf).
+	 There are some RCU critical functions that are called out
+	 of scope for RCU. For example, when NO_HZ_FULL is enabled,
+	 and coming out of user space. The CPU is not being tracked by
+	 RCU and all rcu_read_lock()s will be ignored. These functions
+	 need to be tagged as unsafe for RCU so that only function callbacks
+	 that specify that they do not use RCU will be called by them.
+
+	 This option will enable PROVE_RCU and will enable on boot up
+	 a function callback that traces all functions and uses an
+	 rcu_read_lock(). If any function that is not tagged as unsafe
+	 for RCU is called, a debug splat will be shown. This is used
+	 for finding unsafe RCU callers that need to be tagged.
+
+	 If you don't understand any of this, then say N.
+
 config FTRACE_STARTUP_TEST
 	bool "Perform a startup test on ftrace"
 	depends on GENERIC_TRACER

kernel/trace/ftrace.c +12 -0

index 33e4890..69b7f62 100644
@@ -1359,6 +1359,13 @@ alloc_and_copy_ftrace_hash(int size_bits, struct ftrace_hash *hash)
 	return NULL;
 }
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+bool ftrace_rcu_unsafe(unsigned long addr)
+{
+	return ftrace_lookup_ip(ftrace_unsafe_rcu, addr) != NULL;
+}
+#endif
+
 static void
 ftrace_hash_rec_disable(struct ftrace_ops *ops, int filter_hash);
 static void

@@ -4391,6 +4398,11 @@ static void __init create_unsafe_rcu_hash(void)
 		if (WARN_ON_ONCE(strcmp(str, finder->name) != 0))
 			continue;
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+		/* When checker is enabled, show what was marked unsafe */
+		pr_info("add ftrace rcu unsafe %p (%s)\n",
+			(void *)ip, finder->name);
+#endif
 		add_hash_entry(ftrace_unsafe_rcu, ip);
 	}
 }

kernel/trace/trace.h +3 -0

index 3578be6..e551316 100644
@@ -760,6 +760,9 @@ static inline int ftrace_graph_addr(unsigned long addr)
 
 	return 0;
 }
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+extern bool ftrace_rcu_unsafe(unsigned long addr);
+#endif
 #else
 static inline int ftrace_graph_addr(unsigned long addr)
 {

kernel/trace/trace_functions.c +46 -1

index 38fe148..9dd4627 100644
@@ -559,9 +559,54 @@ static inline int init_func_cmd_traceon(void)
 }
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+static void
+ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
+		       struct ftrace_ops *op, struct pt_regs *pt_regs)
+{
+	int bit;
+
+	preempt_disable_notrace();
+
+	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);
+	if (bit < 0)
+		goto out;
+
+	if (WARN_ONCE(ftrace_rcu_unsafe(ip),
+		      "UNSAFE RCU function called %pS",
+		      (void *)ip))
+		goto out;
+
+	/* Should trigger a RCU splat if called from unsafe RCU function */
+	rcu_read_lock();
+	rcu_read_unlock();
+
+	trace_clear_recursion(bit);
+ out:
+	preempt_enable_notrace();
+}
+
+static struct ftrace_ops ftrace_unsafe_ops = {
+	.func			= ftrace_unsafe_callback,
+	.flags			= FTRACE_OPS_FL_RECURSION_SAFE
+};
+
+static __init void ftrace_start_unsafe_rcu(void)
+{
+	register_ftrace_function(&ftrace_unsafe_ops);
+}
+#else
+static inline void ftrace_start_unsafe_rcu(void) { }
+#endif
+
 static __init int init_function_trace(void)
 {
+	int ret;
+
 	init_func_cmd_traceon();
-	return register_tracer(&function_trace);
+	ret = register_tracer(&function_trace);
+	if (!ret)
+		ftrace_start_unsafe_rcu();
+	return ret;
 }
 core_initcall(init_function_trace);

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

This is a light weight way to keep the rcu checker from checking RCU safety. It adds a ftrace_unsafe_rcu_checker_disable/enable() that increments or decrements a counter respectively. When the counter is set, the RCU unsafe checker callback does not run the tests to see if RCU is safe or not.

This is required by the graph tracer because the checks can cause the graph tracer to live lock the system by its own calls.

It's also needed by the irqsoff tracer, because it may be called in RCU unsafe regions and if its internal functions get traced then the RCU unsafe checker may have some false positives.

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

---
 kernel/trace/trace.h           |   12 +++++++++---
 kernel/trace/trace_functions.c |   15 +++++++++++++++
 2 files changed, 24 insertions(+), 3 deletions(-)

kernel/trace/trace.h +9 -3

index e551316..58e4c37 100644
@@ -760,9 +760,6 @@ static inline int ftrace_graph_addr(unsigned long addr)
 
 	return 0;
 }
-#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
-extern bool ftrace_rcu_unsafe(unsigned long addr);
-#endif
 #else
 static inline int ftrace_graph_addr(unsigned long addr)
 {

@@ -1061,4 +1058,13 @@ int perf_ftrace_event_register(struct ftrace_event_call *call,
 #define perf_ftrace_event_register NULL
 #endif
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+extern bool ftrace_rcu_unsafe(unsigned long addr);
+extern void ftrace_unsafe_rcu_checker_disable(void);
+extern void ftrace_unsafe_rcu_checker_enable(void);
+#else
+static inline void ftrace_unsafe_rcu_checker_disable(void) { }
+static inline void ftrace_unsafe_rcu_checker_enable(void) { }
+#endif
+
 #endif /* _LINUX_KERNEL_TRACE_H */

kernel/trace/trace_functions.c +15 -0

index 9dd4627..1d5f951 100644
@@ -560,12 +560,27 @@ static inline int init_func_cmd_traceon(void)
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
 #ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+static atomic_t ftrace_unsafe_rcu_disabled;
+
+void ftrace_unsafe_rcu_checker_disable(void)
+{
+	atomic_inc(&ftrace_unsafe_rcu_disabled);
+}
+
+void ftrace_unsafe_rcu_checker_enable(void)
+{
+	atomic_dec(&ftrace_unsafe_rcu_disabled);
+}
+
 static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
 	int bit;
 
+	if (atomic_read(&ftrace_unsafe_rcu_disabled))
+		return;
+
 	preempt_disable_notrace();
 
 	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);

Signature · 1 line

1.7.10.4

Quoted 7 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

This is a light weight way to keep the rcu checker from checking RCU safety. It adds a ftrace_unsafe_rcu_checker_disable/enable() that increments or decrements a counter respectively. When the counter is set, the RCU unsafe checker callback does not run the tests to see if RCU is safe or not.

Please add something saying what we do instead of testing RCU safety. Looks to me like it skips not only the tests, but also invoking the callback, but I could easily be wrong.

Quoted 8 lines

This is required by the graph tracer because the checks can cause the graph tracer to live lock the system by its own calls.

It's also needed by the irqsoff tracer, because it may be called in RCU unsafe regions and if its internal functions get traced then the RCU unsafe checker may have some false positives.

Quoted 1 line

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

With the augmented commit log as noted above:

Acked-by Paul E. McKenney <[email protected]>

Quoted 10 lines

---
 kernel/trace/trace.h           |   12 +++++++++---
 kernel/trace/trace_functions.c |   15 +++++++++++++++
 2 files changed, 24 insertions(+), 3 deletions(-)

kernel/trace/trace.h +0 -0

index e551316..58e4c37 100644
@@ -760,9 +760,6 @@ static inline int ftrace_graph_addr(unsigned long addr)

Quoted 7 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

This is a light weight way to keep the rcu checker from checking RCU safety. It adds a ftrace_unsafe_rcu_checker_disable/enable() that increments or decrements a counter respectively. When the counter is set, the RCU unsafe checker callback does not run the tests to see if RCU is safe or not.

Please add something saying what we do instead of testing RCU safety. Looks to me like it skips not only the tests, but also invoking the callback, but I could easily be wrong.

Quoted 3 lines

This is required by the graph tracer because the checks can cause the graph tracer to live lock the system by its own calls.

Quoted 6 lines

It's also needed by the irqsoff tracer, because it may be called in RCU unsafe regions and if its internal functions get traced then the RCU unsafe checker may have some false positives.

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

With the augmented commit log as noted above:

Acked-by Paul E. McKenney <[email protected]>

Quoted 69 lines

---
 kernel/trace/trace.h           |   12 +++++++++---
 kernel/trace/trace_functions.c |   15 +++++++++++++++
 2 files changed, 24 insertions(+), 3 deletions(-)

kernel/trace/trace.h +9 -3

index e551316..58e4c37 100644
@@ -760,9 +760,6 @@ static inline int ftrace_graph_addr(unsigned long addr)
 
 	return 0;
 }
-#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
-extern bool ftrace_rcu_unsafe(unsigned long addr);
-#endif
 #else
 static inline int ftrace_graph_addr(unsigned long addr)
 {

@@ -1061,4 +1058,13 @@ int perf_ftrace_event_register(struct ftrace_event_call *call,
 #define perf_ftrace_event_register NULL
 #endif
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+extern bool ftrace_rcu_unsafe(unsigned long addr);
+extern void ftrace_unsafe_rcu_checker_disable(void);
+extern void ftrace_unsafe_rcu_checker_enable(void);
+#else
+static inline void ftrace_unsafe_rcu_checker_disable(void) { }
+static inline void ftrace_unsafe_rcu_checker_enable(void) { }
+#endif
+
 #endif /* _LINUX_KERNEL_TRACE_H */

kernel/trace/trace_functions.c +15 -0

index 9dd4627..1d5f951 100644
@@ -560,12 +560,27 @@ static inline int init_func_cmd_traceon(void)
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
 #ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+static atomic_t ftrace_unsafe_rcu_disabled;
+
+void ftrace_unsafe_rcu_checker_disable(void)
+{
+	atomic_inc(&ftrace_unsafe_rcu_disabled);
+}
+
+void ftrace_unsafe_rcu_checker_enable(void)
+{
+	atomic_dec(&ftrace_unsafe_rcu_disabled);
+}
+
 static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
 	int bit;
 
+	if (atomic_read(&ftrace_unsafe_rcu_disabled))
+		return;
+
 	preempt_disable_notrace();
 
 	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);

Signature · 1 line

1.7.10.4

Quoted 9 lines · On Sat, 31 Aug 2013 12:52:58 -0700 "Paul E. McKenney"…

Quoted 7 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

This is a light weight way to keep the rcu checker from checking RCU safety. It adds a ftrace_unsafe_rcu_checker_disable/enable() that increments or decrements a counter respectively. When the counter is set, the RCU unsafe checker callback does not run the tests to see if RCU is safe or not.

Quoted 3 lines

Please add something saying what we do instead of testing RCU safety. Looks to me like it skips not only the tests, but also invoking the callback, but I could easily be wrong.

Now that I'm awake and also not on holiday, I can reply with a clear mind.

When disabled, it forces the callback to return immediately. I may in the future, have it disable the callback altogether.

Yes, we can miss checks, but it's better than the test live locking the system :-)

Quoted 3 lines

Quoted 3 lines

This is required by the graph tracer because the checks can cause the graph tracer to live lock the system by its own calls.

I added this (I quoted the added text):

This is a light weight way to keep the rcu checker from checking RCU safety. It adds a ftrace_unsafe_rcu_checker_disable/enable() that increments or decrements a counter respectively. When the counter is set, the RCU unsafe checker callback does not run the tests to see if RCU is safe or not. "But the callback still gets called. It just does not call rcu_read_(un)lock()."

This is required by the graph tracer because the checks can cause the graph tracer to live lock the system by its own calls. "That is, the graph tracer will still trace rcu and the rcu debugging, and this will slow down the checker, which is still calling all other functions (in interrupts and faults), which can cause the timer interrupt to take oven a millisecond to complete, and it will then trigger once it finishes, live locking the system."

Quoted 5 lines

Quoted 5 lines

It's also needed by the irqsoff tracer, because it may be called in RCU unsafe regions and if its internal functions get traced then the RCU unsafe checker may have some false positives.

Quoted 3 lines

Quoted 1 line

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

With the augmented commit log as noted above:

Is the above OK?

-- Steve

Quoted 67 lines

Acked-by Paul E. McKenney <[email protected]>

Quoted 64 lines

---
 kernel/trace/trace.h           |   12 +++++++++---
 kernel/trace/trace_functions.c |   15 +++++++++++++++
 2 files changed, 24 insertions(+), 3 deletions(-)

kernel/trace/trace.h +9 -3

index e551316..58e4c37 100644
@@ -760,9 +760,6 @@ static inline int ftrace_graph_addr(unsigned long addr)
 
 	return 0;
 }
-#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
-extern bool ftrace_rcu_unsafe(unsigned long addr);
-#endif
 #else
 static inline int ftrace_graph_addr(unsigned long addr)
 {

@@ -1061,4 +1058,13 @@ int perf_ftrace_event_register(struct ftrace_event_call *call,
 #define perf_ftrace_event_register NULL
 #endif
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+extern bool ftrace_rcu_unsafe(unsigned long addr);
+extern void ftrace_unsafe_rcu_checker_disable(void);
+extern void ftrace_unsafe_rcu_checker_enable(void);
+#else
+static inline void ftrace_unsafe_rcu_checker_disable(void) { }
+static inline void ftrace_unsafe_rcu_checker_enable(void) { }
+#endif
+
 #endif /* _LINUX_KERNEL_TRACE_H */

kernel/trace/trace_functions.c +15 -0

index 9dd4627..1d5f951 100644
@@ -560,12 +560,27 @@ static inline int init_func_cmd_traceon(void)
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
 #ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+static atomic_t ftrace_unsafe_rcu_disabled;
+
+void ftrace_unsafe_rcu_checker_disable(void)
+{
+	atomic_inc(&ftrace_unsafe_rcu_disabled);
+}
+
+void ftrace_unsafe_rcu_checker_enable(void)
+{
+	atomic_dec(&ftrace_unsafe_rcu_disabled);
+}
+
 static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)
 {
 	int bit;
 
+	if (atomic_read(&ftrace_unsafe_rcu_disabled))
+		return;
+
 	preempt_disable_notrace();
 

Quoted 5 lines

Quoted 5 lines

kernel/trace/trace_functions.c +0 -0

 	bit = trace_test_and_set_recursion(TRACE_FTRACE_START, TRACE_FTRACE_MAX);

Signature · 1 line

1.7.10.4

--
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/

From: "Steven Rostedt (Red Hat)" <[email protected]>

Having the RCU unsafe checker running when function graph is enabled can cause a live lock. That's because the RCU unsafe checker enables full lockdep debugging on RCU which does a lot of interal calls that may be traced by the function graph tacer. This adds quite a bit of

overhead and can possibly live lock the system.

Just do not do the RCU unsafe checks when function graph tracer is enabled.

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

---
 kernel/trace/ftrace.c |    7 +++++++
 1 file changed, 7 insertions(+)

kernel/trace/ftrace.c +7 -0

index 69b7f62..310b727 100644
@@ -5118,6 +5118,12 @@ int register_ftrace_graph(trace_func_graph_ret_t retfunc,
 		goto out;
 	}
 
+	/*
+	 * The Unsafe RCU checker can live lock function graph tracing.
+	 * It's best to just disable it while doing the fgraph tracing.
+	 */
+	ftrace_unsafe_rcu_checker_disable();
+
 	ftrace_graph_return = retfunc;
 	ftrace_graph_entry = entryfunc;
 

@@ -5141,6 +5147,7 @@ void unregister_ftrace_graph(void)
 	ftrace_shutdown(&global_ops, FTRACE_STOP_FUNC_RET);
 	unregister_pm_notifier(&ftrace_suspend_notifier);
 	unregister_trace_sched_switch(ftrace_graph_probe_sched_switch, NULL);
+	ftrace_unsafe_rcu_checker_enable();
 
  out:
 	mutex_unlock(&ftrace_lock);

Signature · 1 line

1.7.10.4

Quoted 6 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

Having the RCU unsafe checker running when function graph is enabled can cause a live lock. That's because the RCU unsafe checker enables full lockdep debugging on RCU which does a lot of interal calls that may be traced by the function graph tacer. This adds quite a bit of

s/tacer/tracer/ (Yeah, yeah, picky, picky!)

Quoted 5 lines

overhead and can possibly live lock the system.

Just do not do the RCU unsafe checks when function graph tracer is enabled.

Quoted 1 line

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

One question: How does the user/tester/developer know that RCU-unsafe checks have been disabled by function-graph tracing? Would it make sense to print something to dmesg calling this out? Or do the transitions happen too often?

Thanx, Paul

Quoted 1 line

---

Quoted 15 lines · Paul E. McKenney

Quoted 6 lines · Steven Rostedt

From: "Steven Rostedt (Red Hat)" <[email protected]>

Having the RCU unsafe checker running when function graph is enabled can cause a live lock. That's because the RCU unsafe checker enables full lockdep debugging on RCU which does a lot of interal calls that may be traced by the function graph tacer. This adds quite a bit of

s/tacer/tracer/ (Yeah, yeah, picky, picky!)

Quoted 5 lines

overhead and can possibly live lock the system.

Just do not do the RCU unsafe checks when function graph tracer is enabled.

Quoted 6 lines

Quoted 1 line

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

One question: How does the user/tester/developer know that RCU-unsafe checks have been disabled by function-graph tracing? Would it make sense to print something to dmesg calling this out? Or do the transitions happen too often?

Ideally, (for 3.13) I plan on having this be a sysctl switch. That will be 1 or 0, depending on if it is enabled or not. But yeah, I can add a printk to show that the kernel changed it. It doesn't happen often, and mainly by a user (or selftest).

From: "Steven Rostedt (Red Hat)" <[email protected]>

The irqsoff tracer can be called during some of the RCU unsafe regions. The proble is that some of the internal calls that it

makes may also be traced. For example, it uses spin locks. But if the spin lock gets traced and the RCU unsafe checker runs, it will trigger that RCU is not safe to use. But the only reason a spin lock is being used in an RCU unsafe region is because the irqsoff trace uses it, and causes a false positive.

Disable the unsafe RCU checker when irqsoff is enabled.

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

---
 kernel/trace/trace_irqsoff.c |   16 ++++++++++++++--
 1 file changed, 14 insertions(+), 2 deletions(-)

kernel/trace/trace_irqsoff.c +14 -2

index 2aefbee..62d603c 100644
@@ -584,9 +584,14 @@ static int start_irqsoff_tracer(struct trace_array *tr, int graph)
 
 	ret = register_irqsoff_function(graph, 0);
 
-	if (!ret && tracing_is_enabled())
+	if (!ret && tracing_is_enabled()) {
+		/*
+		 * irqsoff tracer can cause unsafe rcu checker
+		 * to have false positives.
+		 */
+		ftrace_unsafe_rcu_checker_disable();
 		tracer_enabled = 1;
-	else
+	} else
 		tracer_enabled = 0;
 
 	return ret;

@@ -594,6 +599,9 @@ static int start_irqsoff_tracer(struct trace_array *tr, int graph)
 
 static void stop_irqsoff_tracer(struct trace_array *tr, int graph)
 {
+	if (tracer_enabled)
+		ftrace_unsafe_rcu_checker_enable();
+
 	tracer_enabled = 0;
 
 	unregister_irqsoff_function(graph);

@@ -630,11 +638,15 @@ static void irqsoff_tracer_reset(struct trace_array *tr)
 
 static void irqsoff_tracer_start(struct trace_array *tr)
 {
+	if (!tracer_enabled)
+		ftrace_unsafe_rcu_checker_disable();
 	tracer_enabled = 1;
 }
 
 static void irqsoff_tracer_stop(struct trace_array *tr)
 {
+	if (tracer_enabled)
+		ftrace_unsafe_rcu_checker_enable();
 	tracer_enabled = 0;
 }
 

Signature · 1 line

1.7.10.4

From: "Steven Rostedt (Red Hat)" <[email protected]>

When the RCU lockdep splat hits because of the unsafe RCU checker, the backtrace does not always show the culprit. But the culprit was passed to the unsafe RCU checker.

Save the ip of the function being traced in a per_cpu variable, and when the RCU lockdep detects a problem, it can also print out what function was being traced if it was caused by the unsafe RCU checker.

Cc Peter Zijlstra <[email protected]>

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

---
 include/linux/ftrace.h         |    6 ++++++
 kernel/lockdep.c               |    2 ++
 kernel/trace/trace_functions.c |   14 ++++++++++++++
 3 files changed, 22 insertions(+)

include/linux/ftrace.h +6 -0

index 4752764..3dbb946 100644
@@ -885,4 +885,10 @@ unsigned long arch_syscall_addr(int nr);
 
 #endif /* CONFIG_FTRACE_SYSCALLS */
 
+#ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+extern void print_ftrace_rcu_func(int cpu);
+#else
+static inline void print_ftrace_rcu_func(int cpu) { }
+#endif
+
 #endif /* _LINUX_FTRACE_H */

kernel/lockdep.c +2 -0

index e16c45b..74272ed 100644
@@ -4229,6 +4229,8 @@ void lockdep_rcu_suspicious(const char *file, const int line, const char *s)
 				: "",
 	       rcu_scheduler_active, debug_locks);
 
+	print_ftrace_rcu_func(raw_smp_processor_id());
+
 	/*
 	 * If a CPU is in the RCU-free window in idle (ie: in the section
 	 * between rcu_idle_enter() and rcu_idle_exit(), then RCU

kernel/trace/trace_functions.c +14 -0

index 1d5f951..f5a9031 100644
@@ -560,6 +560,7 @@ static inline int init_func_cmd_traceon(void)
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
 #ifdef CONFIG_FTRACE_UNSAFE_RCU_CHECKER
+
 static atomic_t ftrace_unsafe_rcu_disabled;
 
 void ftrace_unsafe_rcu_checker_disable(void)

@@ -572,6 +573,17 @@ void ftrace_unsafe_rcu_checker_enable(void)
 	atomic_dec(&ftrace_unsafe_rcu_disabled);
 }
 
+static DEFINE_PER_CPU(unsigned long, ftrace_rcu_func);
+
+void print_ftrace_rcu_func(int cpu)
+{
+	unsigned long ip = per_cpu(ftrace_rcu_func, cpu);
+
+	if (ip)
+		printk("ftrace_rcu_func: %pS\n",
+		       (void *)per_cpu(ftrace_rcu_func, cpu));
+}
+
 static void
 ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		       struct ftrace_ops *op, struct pt_regs *pt_regs)

@@ -592,9 +604,11 @@ ftrace_unsafe_callback(unsigned long ip, unsigned long parent_ip,
 		      (void *)ip))
 		goto out;
 
+	this_cpu_write(ftrace_rcu_func, ip);
 	/* Should trigger a RCU splat if called from unsafe RCU function */
 	rcu_read_lock();
 	rcu_read_unlock();
+	this_cpu_write(ftrace_rcu_func, 0);
 
 	trace_clear_recursion(bit);
  out:

Signature · 1 line

1.7.10.4

kernel/trace/trace_functions.c void ftrace_unsafe_rcu_checker_enable(void) · line 585

Quoted 8 lines · Steven Rostedt

kernel/trace/trace_functions.c +8 -0

+void print_ftrace_rcu_func(int cpu)
+{
+	unsigned long ip = per_cpu(ftrace_rcu_func, cpu);
+
+	if (ip)
+		printk("ftrace_rcu_func: %pS\n",
+		       (void *)per_cpu(ftrace_rcu_func, cpu));
+}

That's missing { }.

Quoted 11 lines · On Thu, 5 Sep 2013 21:18:39 +0200 Peter Zijlstra <[email protected]> wrote:

kernel/trace/trace_functions.c void ftrace_unsafe_rcu_checker_enable(void) · line 585

Quoted 8 lines · Steven Rostedt

kernel/trace/trace_functions.c +8 -0

+void print_ftrace_rcu_func(int cpu)
+{
+	unsigned long ip = per_cpu(ftrace_rcu_func, cpu);
+
+	if (ip)
+		printk("ftrace_rcu_func: %pS\n",
+		       (void *)per_cpu(ftrace_rcu_func, cpu));
+}

That's missing { }.

Hmm, that's an interesting point. Why the { } because I break up the printk for the 80 character limit?

Although, I'm still not convinced that it needs { }, as it looks to me that it flows nicely without it. I can't find a place in CodingStyle that says { } are needed here.

Quoted 15 lines · Steven Rostedt

Quoted 11 lines · On Thu, 5 Sep 2013 21:18:39 +0200 Peter Zijlstra <[email protected]> wrote:

kernel/trace/trace_functions.c void ftrace_unsafe_rcu_checker_enable(void) · line 585

Quoted 8 lines · Steven Rostedt

kernel/trace/trace_functions.c +8 -0

+void print_ftrace_rcu_func(int cpu)
+{
+	unsigned long ip = per_cpu(ftrace_rcu_func, cpu);
+
+	if (ip)
+		printk("ftrace_rcu_func: %pS\n",
+		       (void *)per_cpu(ftrace_rcu_func, cpu));
+}

That's missing { }.

Quoted 2 lines

Hmm, that's an interesting point. Why the { } because I break up the printk for the 80 character limit?

You probably shouldn't break it up - it looks uglier.

Quoted 4 lines

Although, I'm still not convinced that it needs { }, as it looks to me that it flows nicely without it. I can't find a place in CodingStyle that says { } are needed here.

it's somewhat of a grey area - the section quoted below talks about it broadly - and it's typically understood to apply to multi-line statements as well, as it's easy to overlook and confuse multi-statements with multi-line statements...

From: "Steven Rostedt (Red Hat)" <[email protected]>

When the RCU lockdep splat hits because of the unsafe RCU checker, the backtrace does not always show the culprit. But the culprit was passed to the unsafe RCU checker.

Save the ip of the function being traced in a per_cpu variable, and when the RCU lockdep detects a problem, it can also print out what function was being traced if it was caused by the unsafe RCU checker.