Skip to contentSkip to conversation

tracing: updates and fixes for 3.10

PATCH In review Steven Rostedt 2 participants 27 messages Jul 2, 2013 – Apr 10, 2014

Subsystems (4)
lore
Share & tools
lore

Steven Rostedt

author maintainer
#0 lore raw

cover tracing: updates and fixes for 3.10

This set of patches mostly consists of fixes for 3.10. I'm posting this and putting it into linux-next for a few days before asking Linus to pull.

I'll probably add a few more patches to linux-next as well, as there's a few more bugs that have been discovered lately.

-- Steve

Alexander Z Lam (2):
tracing: Make trace_marker use the correct per-instance buffer
tracing: Protect ftrace_trace_arrays list in trace_events.c

Oleg Nesterov (4):
tracing/kprobes: Avoid perf_trace_buf_*() if ->perf_events is empty tracing/kprobes: Kill probe_enable_lock tracing/kprobes: Turn trace_probe->files into list_head tracing/kprobes: Don't pass addr=ip to perf_trace_buf_submit()

Steven Rostedt (1):
tracing: Failed to create system directory

Steven Rostedt (Red Hat) (4):
tracing: Use flag buffer_disabled for irqsoff tracer
ftrace: Do not run selftest if command line parameter is set
tracing: Add trace_array_get/put() to handle instance refs better
tracing: Get trace_array ref counts when accessing trace files

Tom Zanussi (3):
tracing: Simplify code for showing of soft disabled flag
tracing: Add missing syscall_metadata comment
tracing: Fix disabling of soft disable

----

 include/trace/syscall.h       |    1 +
 kernel/trace/ftrace.c         |    5 +
 kernel/trace/trace.c          |  310 +++++++++++++++++++++++++++++++++--------
 kernel/trace/trace.h          |    3 +
 kernel/trace/trace_events.c   |   76 +++++++---
 kernel/trace/trace_irqsoff.c  |    4 +-
 kernel/trace/trace_kprobe.c   |  187 ++++++++-----------------
 kernel/trace/trace_selftest.c |   18 ++-
 8 files changed, 396 insertions(+), 208 deletions(-)
author maintainer
#1 lore raw

PATCH 1/14 tracing: Failed to create system directory

From: Steven Rostedt <[email protected]>

Running the following:

 # cd /sys/kernel/debug/tracing
 # echo p:i do_sys_open > kprobe_events
 # echo p:j schedule >> kprobe_events
 # cat kprobe_events
p:kprobes/i do_sys_open
p:kprobes/j schedule
 # echo p:i do_sys_open >> kprobe_events
 # cat kprobe_events
p:kprobes/j schedule
p:kprobes/i do_sys_open
 # ls /sys/kernel/debug/tracing/events/kprobes/
enable  filter  j

Notice that the 'i' is missing from the kprobes directory.

The console produces:

"Failed to create system directory kprobes"

This is because kprobes passes in a allocated name for the system and the ftrace event subsystem saves off that name instead of creating a duplicate for it. But the kprobes may free the system name making the pointer to it invalid.

This bug was introduced by 92edca073c37 "tracing: Use direct field, type and system names" which switched from using kstrdup() on the system name in favor of just keeping apointer to it, as the internal ftrace event system names are static and exist for the life of the computer being booted.

Instead of reverting back to duplicating system names again, we can use core_kernel_data() to determine if the passed in name was allocated or static. Then use the MSB of the ref_count to be a flag to keep track if the name was allocated or not. Then we can still save from having to duplicate strings that will always exist, but still copy the ones that may be freed.

---
 kernel/trace/trace_events.c |   41 +++++++++++++++++++++++++++++++++++------
 1 file changed, 35 insertions(+), 6 deletions(-)
kernel/trace/trace_events.c +35 -6
index f57b015..903a0bf 100644
@@ -41,6 +41,23 @@ static LIST_HEAD(ftrace_common_fields);
 static struct kmem_cache *field_cachep;
 static struct kmem_cache *file_cachep;
 
+#define SYSTEM_FL_FREE_NAME		(1 << 31)
+
+static inline int system_refcount(struct event_subsystem *system)
+{
+	return system->ref_count & ~SYSTEM_FL_FREE_NAME;
+}
+
+static int system_refcount_inc(struct event_subsystem *system)
+{
+	return (system->ref_count++) & ~SYSTEM_FL_FREE_NAME;
+}
+
+static int system_refcount_dec(struct event_subsystem *system)
+{
+	return (--system->ref_count) & ~SYSTEM_FL_FREE_NAME;
+}
+
 /* Double loops, do not use break, only goto's work */
 #define do_for_each_event_file(tr, file)			\
 	list_for_each_entry(tr, &ftrace_trace_arrays, list) {	\
@@ -344,8 +361,8 @@ static void __put_system(struct event_subsystem *system)
 {
 	struct event_filter *filter = system->filter;
 
-	WARN_ON_ONCE(system->ref_count == 0);
-	if (--system->ref_count)
+	WARN_ON_ONCE(system_refcount(system) == 0);
+	if (system_refcount_dec(system))
 		return;
 
 	list_del(&system->list);
@@ -354,13 +371,15 @@ static void __put_system(struct event_subsystem *system)
 		kfree(filter->filter_string);
 		kfree(filter);
 	}
+	if (system->ref_count & SYSTEM_FL_FREE_NAME)
+		kfree(system->name);
 	kfree(system);
 }
 
 static void __get_system(struct event_subsystem *system)
 {
-	WARN_ON_ONCE(system->ref_count == 0);
-	system->ref_count++;
+	WARN_ON_ONCE(system_refcount(system) == 0);
+	system_refcount_inc(system);
 }
 
 static void __get_system_dir(struct ftrace_subsystem_dir *dir)
@@ -374,7 +393,7 @@ static void __put_system_dir(struct ftrace_subsystem_dir *dir)
 {
 	WARN_ON_ONCE(dir->ref_count == 0);
 	/* If the subsystem is about to be freed, the dir must be too */
-	WARN_ON_ONCE(dir->subsystem->ref_count == 1 && dir->ref_count != 1);
+	WARN_ON_ONCE(system_refcount(dir->subsystem) == 1 && dir->ref_count != 1);
 
 	__put_system(dir->subsystem);
 	if (!--dir->ref_count)
@@ -1274,7 +1293,15 @@ create_new_subsystem(const char *name)
 		return NULL;
 
 	system->ref_count = 1;
-	system->name = name;
+
+	/* Only allocate if dynamic (kprobes and modules) */
+	if (!core_kernel_data((unsigned long)name)) {
+		system->ref_count |= SYSTEM_FL_FREE_NAME;
+		system->name = kstrdup(name, GFP_KERNEL);
+		if (!system->name)
+			goto out_free;
+	} else
+		system->name = name;
 
 	system->filter = NULL;
 
@@ -1287,6 +1314,8 @@ create_new_subsystem(const char *name)
 	return system;
 
  out_free:
+	if (system->ref_count & SYSTEM_FL_FREE_NAME)
+		kfree(system->name);
 	kfree(system);
 	return NULL;
 }
Signature · 1 line
1.7.10.4
author maintainer
#2 lore raw

PATCH 2/14 tracing/kprobes: Avoid perf_trace_buf_*() if ->perf_events is empty

In reply to Steven Rostedt

From: Oleg Nesterov <[email protected]>

perf_trace_buf_prepare() + perf_trace_buf_submit() make no sense if this task/CPU has no active counters. Change kprobe_perf_func() and kretprobe_perf_func() to check call->perf_events beforehand and return if this list is empty.

For example, "perf record -e some_probe -p1". Only /sbin/init will report, all other threads which hit the same probe will do perf_trace_buf_prepare/perf_trace_buf_submit just to realize that nobody wants perf_swevent_event().

---
 kernel/trace/trace_kprobe.c |   12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)
kernel/trace/trace_kprobe.c +8 -4
index f237417..c35bebe 100644
@@ -1156,6 +1156,10 @@ kprobe_perf_func(struct trace_probe *tp, struct pt_regs *regs)
 	int size, __size, dsize;
 	int rctx;
 
+	head = this_cpu_ptr(call->perf_events);
+	if (hlist_empty(head))
+		return;
+
 	dsize = __get_data_size(tp, regs);
 	__size = sizeof(*entry) + tp->size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
@@ -1171,8 +1175,6 @@ kprobe_perf_func(struct trace_probe *tp, struct pt_regs *regs)
 	entry->ip = (unsigned long)tp->rp.kp.addr;
 	memset(&entry[1], 0, dsize);
 	store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);
-
-	head = this_cpu_ptr(call->perf_events);
 	perf_trace_buf_submit(entry, size, rctx,
 					entry->ip, 1, regs, head, NULL);
 }
@@ -1188,6 +1190,10 @@ kretprobe_perf_func(struct trace_probe *tp, struct kretprobe_instance *ri,
 	int size, __size, dsize;
 	int rctx;
 
+	head = this_cpu_ptr(call->perf_events);
+	if (hlist_empty(head))
+		return;
+
 	dsize = __get_data_size(tp, regs);
 	__size = sizeof(*entry) + tp->size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
@@ -1203,8 +1209,6 @@ kretprobe_perf_func(struct trace_probe *tp, struct kretprobe_instance *ri,
 	entry->func = (unsigned long)tp->rp.kp.addr;
 	entry->ret_ip = (unsigned long)ri->ret_addr;
 	store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);
-
-	head = this_cpu_ptr(call->perf_events);
 	perf_trace_buf_submit(entry, size, rctx,
 					entry->ret_ip, 1, regs, head, NULL);
 }
Signature · 1 line
1.7.10.4
author maintainer
#3 lore raw

PATCH 3/14 tracing/kprobes: Kill probe_enable_lock

In reply to Steven Rostedt

From: Oleg Nesterov <[email protected]>

enable_trace_probe() and disable_trace_probe() should not worry about serialization, the caller (perf_trace_init or __ftrace_set_clr_event) holds event_mutex.

They are also called by kprobe_trace_self_tests_init(), but this __init function can't race with itself or trace_events.c

And note that this code depended on event_mutex even before 41a7dd420c which introduced probe_enable_lock. In fact it assumes that the caller kprobe_register() can never race with itself. Otherwise, say, tp->flags manipulations are racy.

---
 kernel/trace/trace_kprobe.c |   43 ++++++++++++++++++++-----------------------
 1 file changed, 20 insertions(+), 23 deletions(-)
kernel/trace/trace_kprobe.c +20 -23
index c35bebe..282f86c 100644
@@ -183,16 +183,15 @@ static struct trace_probe *find_trace_probe(const char *event,
 	return NULL;
 }
 
+/*
+ * This and enable_trace_probe/disable_trace_probe rely on event_mutex
+ * held by the caller, __ftrace_set_clr_event().
+ */
 static int trace_probe_nr_files(struct trace_probe *tp)
 {
-	struct ftrace_event_file **file;
+	struct ftrace_event_file **file = rcu_dereference_raw(tp->files);
 	int ret = 0;
 
-	/*
-	 * Since all tp->files updater is protected by probe_enable_lock,
-	 * we don't need to lock an rcu_read_lock.
-	 */
-	file = rcu_dereference_raw(tp->files);
 	if (file)
 		while (*(file++))
 			ret++;
@@ -200,8 +199,6 @@ static int trace_probe_nr_files(struct trace_probe *tp)
 	return ret;
 }
 
-static DEFINE_MUTEX(probe_enable_lock);
-
 /*
  * Enable trace_probe
  * if the file is NULL, enable "perf" handler, or enable "trace" handler.
@@ -211,8 +208,6 @@ enable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 {
 	int ret = 0;
 
-	mutex_lock(&probe_enable_lock);
-
 	if (file) {
 		struct ftrace_event_file **new, **old;
 		int n = trace_probe_nr_files(tp);
@@ -223,7 +218,7 @@ enable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 			      GFP_KERNEL);
 		if (!new) {
 			ret = -ENOMEM;
-			goto out_unlock;
+			goto out;
 		}
 		memcpy(new, old, n * sizeof(struct ftrace_event_file *));
 		new[n] = file;
@@ -246,10 +241,7 @@ enable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 		else
 			ret = enable_kprobe(&tp->rp.kp);
 	}
-
- out_unlock:
-	mutex_unlock(&probe_enable_lock);
-
+ out:
 	return ret;
 }
 
@@ -282,8 +274,6 @@ disable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 {
 	int ret = 0;
 
-	mutex_lock(&probe_enable_lock);
-
 	if (file) {
 		struct ftrace_event_file **new, **old;
 		int n = trace_probe_nr_files(tp);
@@ -292,7 +282,7 @@ disable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 		old = rcu_dereference_raw(tp->files);
 		if (n == 0 || trace_probe_file_index(tp, file) < 0) {
 			ret = -EINVAL;
-			goto out_unlock;
+			goto out;
 		}
 
 		if (n == 1) {	/* Remove the last file */
@@ -303,7 +293,7 @@ disable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 				      GFP_KERNEL);
 			if (!new) {
 				ret = -ENOMEM;
-				goto out_unlock;
+				goto out;
 			}
 
 			/* This copy & check loop copies the NULL stopper too */
@@ -326,10 +316,7 @@ disable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 		else
 			disable_kprobe(&tp->rp.kp);
 	}
-
- out_unlock:
-	mutex_unlock(&probe_enable_lock);
-
+ out:
 	return ret;
 }
 
@@ -1214,6 +1201,12 @@ kretprobe_perf_func(struct trace_probe *tp, struct kretprobe_instance *ri,
 }
 #endif	/* CONFIG_PERF_EVENTS */
 
+/*
+ * called by perf_trace_init() or __ftrace_set_clr_event() under event_mutex.
+ *
+ * kprobe_trace_self_tests_init() does enable_trace_probe/disable_trace_probe
+ * lockless, but we can't race with this __init function.
+ */
 static __kprobes
 int kprobe_register(struct ftrace_event_call *event,
 		    enum trace_reg type, void *data)
@@ -1379,6 +1372,10 @@ find_trace_probe_file(struct trace_probe *tp, struct trace_array *tr)
 	return NULL;
 }
 
+/*
+ * Nobody but us can call enable_trace_probe/disable_trace_probe at this
+ * stage, we can do this lockless.
+ */
 static __init int kprobe_trace_self_tests_init(void)
 {
 	int ret, warn = 0;
Signature · 1 line
1.7.10.4
author maintainer
#4 lore raw

PATCH 4/14 tracing: Simplify code for showing of soft disabled flag

In reply to Steven Rostedt

From: Tom Zanussi <[email protected]>

Rather than enumerating each permutation, build the enable state string up from the combination of states. This also allows for the simpler addition of more states.

---
 kernel/trace/trace_events.c |   20 ++++++++++----------
 1 file changed, 10 insertions(+), 10 deletions(-)
kernel/trace/trace_events.c +10 -10
index 903a0bf..7ee08b9 100644
@@ -638,17 +638,17 @@ event_enable_read(struct file *filp, char __user *ubuf, size_t cnt,
 		  loff_t *ppos)
 {
 	struct ftrace_event_file *file = filp->private_data;
-	char *buf;
+	char buf[4] = "0";
 
-	if (file->flags & FTRACE_EVENT_FL_ENABLED) {
-		if (file->flags & FTRACE_EVENT_FL_SOFT_DISABLED)
-			buf = "0*\n";
-		else if (file->flags & FTRACE_EVENT_FL_SOFT_MODE)
-			buf = "1*\n";
-		else
-			buf = "1\n";
-	} else
-		buf = "0\n";
+	if (file->flags & FTRACE_EVENT_FL_ENABLED &&
+	    !(file->flags & FTRACE_EVENT_FL_SOFT_DISABLED))
+		strcpy(buf, "1");
+
+	if (file->flags & FTRACE_EVENT_FL_SOFT_DISABLED ||
+	    file->flags & FTRACE_EVENT_FL_SOFT_MODE)
+		strcat(buf, "*");
+
+	strcat(buf, "\n");
 
 	return simple_read_from_buffer(ubuf, cnt, ppos, buf, strlen(buf));
 }
Signature · 1 line
1.7.10.4
author maintainer
#5 lore raw

PATCH 5/14 tracing: Add missing syscall_metadata comment

In reply to Steven Rostedt

From: Tom Zanussi <[email protected]>

Add the missing syscall_metadata description for the enter_fields struct member.

---
 include/trace/syscall.h |    1 +
 1 file changed, 1 insertion(+)
include/trace/syscall.h +1 -0
index 84bc419..fed853f 100644
@@ -16,6 +16,7 @@
  * @nb_args: number of parameters it takes
  * @types: list of types as strings
  * @args: list of args as strings (args[i] matches types[i])
+ * @enter_fields: list of fields for syscall_enter trace event
  * @enter_event: associated syscall_enter trace event
  * @exit_event: associated syscall_exit trace event
  */
Signature · 1 line
1.7.10.4
author maintainer
#6 lore raw

PATCH 6/14 tracing: Fix disabling of soft disable

In reply to Steven Rostedt

From: Tom Zanussi <[email protected]>

The comment on the soft disable 'disable' case of __ftrace_event_enable_disable() states that the soft disable bit should be cleared in that case, but currently only the soft mode bit is actually cleared.

This essentially leaves the standard non-soft-enable enable/disable paths as the only way to clear the soft disable flag, but the soft disable bit should also be cleared when removing a trigger with '!'.

Also, the SOFT_DISABLED bit should never be set if SOFT_MODE is cleared.

This fixes the above discrepancies.

---
 kernel/trace/trace_events.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)
kernel/trace/trace_events.c +3 -1
index 7ee08b9..5892470 100644
@@ -291,9 +291,11 @@ static int __ftrace_event_enable_disable(struct ftrace_event_file *file,
 			}
 			call->class->reg(call, TRACE_REG_UNREGISTER, file);
 		}
-		/* If in SOFT_MODE, just set the SOFT_DISABLE_BIT */
+		/* If in SOFT_MODE, just set the SOFT_DISABLE_BIT, else clear it */
 		if (file->flags & FTRACE_EVENT_FL_SOFT_MODE)
 			set_bit(FTRACE_EVENT_FL_SOFT_DISABLED_BIT, &file->flags);
+		else
+			clear_bit(FTRACE_EVENT_FL_SOFT_DISABLED_BIT, &file->flags);
 		break;
 	case 1:
 		/*
Signature · 1 line
1.7.10.4
author maintainer
#7 lore raw

PATCH 7/14 tracing/kprobes: Turn trace_probe->files into list_head

In reply to Steven Rostedt

From: Oleg Nesterov <[email protected]>

I think that "ftrace_event_file *trace_probe[]" complicates the code for no reason, turn it into list_head to simplify the code. enable_trace_probe() no longer needs synchronize_sched().

This needs the extra sizeof(list_head) memory for every attached ftrace_event_file, hopefully not a problem in this case.

---
 kernel/trace/trace_kprobe.c |  138 ++++++++++++-------------------------------
 1 file changed, 37 insertions(+), 101 deletions(-)
kernel/trace/trace_kprobe.c +37 -101
index 282f86c..405b5b0 100644
@@ -35,12 +35,17 @@ struct trace_probe {
 	const char		*symbol;	/* symbol name */
 	struct ftrace_event_class	class;
 	struct ftrace_event_call	call;
-	struct ftrace_event_file * __rcu *files;
+	struct list_head	files;
 	ssize_t			size;		/* trace entry size */
 	unsigned int		nr_args;
 	struct probe_arg	args[];
 };
 
+struct event_file_link {
+	struct ftrace_event_file	*file;
+	struct list_head		list;
+};
+
 #define SIZEOF_TRACE_PROBE(n)			\
 	(offsetof(struct trace_probe, args) +	\
 	(sizeof(struct probe_arg) * (n)))
@@ -150,6 +155,7 @@ static struct trace_probe *alloc_trace_probe(const char *group,
 		goto error;
 
 	INIT_LIST_HEAD(&tp->list);
+	INIT_LIST_HEAD(&tp->files);
 	return tp;
 error:
 	kfree(tp->call.name);
@@ -184,22 +190,6 @@ static struct trace_probe *find_trace_probe(const char *event,
 }
 
 /*
- * This and enable_trace_probe/disable_trace_probe rely on event_mutex
- * held by the caller, __ftrace_set_clr_event().
- */
-static int trace_probe_nr_files(struct trace_probe *tp)
-{
-	struct ftrace_event_file **file = rcu_dereference_raw(tp->files);
-	int ret = 0;
-
-	if (file)
-		while (*(file++))
-			ret++;
-
-	return ret;
-}
-
-/*
  * Enable trace_probe
  * if the file is NULL, enable "perf" handler, or enable "trace" handler.
  */
@@ -209,29 +199,18 @@ enable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 	int ret = 0;
 
 	if (file) {
-		struct ftrace_event_file **new, **old;
-		int n = trace_probe_nr_files(tp);
-
-		old = rcu_dereference_raw(tp->files);
-		/* 1 is for new one and 1 is for stopper */
-		new = kzalloc((n + 2) * sizeof(struct ftrace_event_file *),
-			      GFP_KERNEL);
-		if (!new) {
+		struct event_file_link *link;
+
+		link = kmalloc(sizeof(*link), GFP_KERNEL);
+		if (!link) {
 			ret = -ENOMEM;
 			goto out;
 		}
-		memcpy(new, old, n * sizeof(struct ftrace_event_file *));
-		new[n] = file;
-		/* The last one keeps a NULL */
 
-		rcu_assign_pointer(tp->files, new);
-		tp->flags |= TP_FLAG_TRACE;
+		link->file = file;
+		list_add_tail_rcu(&link->list, &tp->files);
 
-		if (old) {
-			/* Make sure the probe is done with old files */
-			synchronize_sched();
-			kfree(old);
-		}
+		tp->flags |= TP_FLAG_TRACE;
 	} else
 		tp->flags |= TP_FLAG_PROFILE;
 
@@ -245,24 +224,16 @@ enable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 	return ret;
 }
 
-static int
-trace_probe_file_index(struct trace_probe *tp, struct ftrace_event_file *file)
+static struct event_file_link *
+find_event_file_link(struct trace_probe *tp, struct ftrace_event_file *file)
 {
-	struct ftrace_event_file **files;
-	int i;
+	struct event_file_link *link;
 
-	/*
-	 * Since all tp->files updater is protected by probe_enable_lock,
-	 * we don't need to lock an rcu_read_lock.
-	 */
-	files = rcu_dereference_raw(tp->files);
-	if (files) {
-		for (i = 0; files[i]; i++)
-			if (files[i] == file)
-				return i;
-	}
+	list_for_each_entry(link, &tp->files, list)
+		if (link->file == file)
+			return link;
 
-	return -1;
+	return NULL;
 }
 
 /*
@@ -275,38 +246,23 @@ disable_trace_probe(struct trace_probe *tp, struct ftrace_event_file *file)
 	int ret = 0;
 
 	if (file) {
-		struct ftrace_event_file **new, **old;
-		int n = trace_probe_nr_files(tp);
-		int i, j;
+		struct event_file_link *link;
 
-		old = rcu_dereference_raw(tp->files);
-		if (n == 0 || trace_probe_file_index(tp, file) < 0) {
+		link = find_event_file_link(tp, file);
+		if (!link) {
 			ret = -EINVAL;
 			goto out;
 		}
 
-		if (n == 1) {	/* Remove the last file */
-			tp->flags &= ~TP_FLAG_TRACE;
-			new = NULL;
-		} else {
-			new = kzalloc(n * sizeof(struct ftrace_event_file *),
-				      GFP_KERNEL);
-			if (!new) {
-				ret = -ENOMEM;
-				goto out;
-			}
-
-			/* This copy & check loop copies the NULL stopper too */
-			for (i = 0, j = 0; j < n && i < n + 1; i++)
-				if (old[i] != file)
-					new[j++] = old[i];
-		}
+		list_del_rcu(&link->list);
+		/* synchronize with kprobe_trace_func/kretprobe_trace_func */
+		synchronize_sched();
+		kfree(link);
 
-		rcu_assign_pointer(tp->files, new);
+		if (!list_empty(&tp->files))
+			goto out;
 
-		/* Make sure the probe is done with old files */
-		synchronize_sched();
-		kfree(old);
+		tp->flags &= ~TP_FLAG_TRACE;
 	} else
 		tp->flags &= ~TP_FLAG_PROFILE;
 
@@ -871,20 +827,10 @@ __kprobe_trace_func(struct trace_probe *tp, struct pt_regs *regs,
 static __kprobes void
 kprobe_trace_func(struct trace_probe *tp, struct pt_regs *regs)
 {
-	/*
-	 * Note: preempt is already disabled around the kprobe handler.
-	 * However, we still need an smp_read_barrier_depends() corresponding
-	 * to smp_wmb() in rcu_assign_pointer() to access the pointer.
-	 */
-	struct ftrace_event_file **file = rcu_dereference_raw(tp->files);
-
-	if (unlikely(!file))
-		return;
+	struct event_file_link *link;
 
-	while (*file) {
-		__kprobe_trace_func(tp, regs, *file);
-		file++;
-	}
+	list_for_each_entry_rcu(link, &tp->files, list)
+		__kprobe_trace_func(tp, regs, link->file);
 }
 
 /* Kretprobe handler */
@@ -931,20 +877,10 @@ static __kprobes void
 kretprobe_trace_func(struct trace_probe *tp, struct kretprobe_instance *ri,
 		     struct pt_regs *regs)
 {
-	/*
-	 * Note: preempt is already disabled around the kprobe handler.
-	 * However, we still need an smp_read_barrier_depends() corresponding
-	 * to smp_wmb() in rcu_assign_pointer() to access the pointer.
-	 */
-	struct ftrace_event_file **file = rcu_dereference_raw(tp->files);
-
-	if (unlikely(!file))
-		return;
+	struct event_file_link *link;
 
-	while (*file) {
-		__kretprobe_trace_func(tp, ri, regs, *file);
-		file++;
-	}
+	list_for_each_entry_rcu(link, &tp->files, list)
+		__kretprobe_trace_func(tp, ri, regs, link->file);
 }
 
 /* Event entry printers */
Signature · 1 line
1.7.10.4
author maintainer
#8 lore raw

PATCH 8/14 tracing: Use flag buffer_disabled for irqsoff tracer

In reply to Steven Rostedt

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

If the ring buffer is disabled and the irqsoff tracer records a trace it will clear out its buffer and lose the data it had previously recorded.

Currently there's a callback when writing to the tracing_of file, but if tracing is disabled via the function tracer trigger, it will not inform the irqsoff tracer to stop recording.

By using the "mirror" flag (buffer_disabled) in the trace_array, that keeps track of the status of the trace_array's buffer, it gives the irqsoff tracer a fast way to know if it should record a new trace or not. The flag may be a little behind the real state of the buffer, but it should not affect the trace too much. It's more important for the irqsoff tracer to be fast.

---
 kernel/trace/trace.c         |  101 +++++++++++++++++++++++++++++-------------
 kernel/trace/trace_irqsoff.c |    4 +-
 2 files changed, 72 insertions(+), 33 deletions(-)
kernel/trace/trace.c +70 -31
index c4c9296..0dc5071 100644
@@ -226,9 +226,24 @@ cycle_t ftrace_now(int cpu)
 	return ts;
 }
 
+/**
+ * tracing_is_enabled - Show if global_trace has been disabled
+ *
+ * Shows if the global trace has been enabled or not. It uses the
+ * mirror flag "buffer_disabled" to be used in fast paths such as for
+ * the irqsoff tracer. But it may be inaccurate due to races. If you
+ * need to know the accurate state, use tracing_is_on() which is a little
+ * slower, but accurate.
+ */
 int tracing_is_enabled(void)
 {
-	return tracing_is_on();
+	/*
+	 * For quick access (irqsoff uses this in fast path), just
+	 * return the mirror variable of the state of the ring buffer.
+	 * It's a little racy, but we don't really care.
+	 */
+	smp_rmb();
+	return !global_trace.buffer_disabled;
 }
 
 /*
@@ -341,6 +356,23 @@ unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
 	TRACE_ITER_GRAPH_TIME | TRACE_ITER_RECORD_CMD | TRACE_ITER_OVERWRITE |
 	TRACE_ITER_IRQ_INFO | TRACE_ITER_MARKERS | TRACE_ITER_FUNCTION;
 
+void tracer_tracing_on(struct trace_array *tr)
+{
+	if (tr->trace_buffer.buffer)
+		ring_buffer_record_on(tr->trace_buffer.buffer);
+	/*
+	 * This flag is looked at when buffers haven't been allocated
+	 * yet, or by some tracers (like irqsoff), that just want to
+	 * know if the ring buffer has been disabled, but it can handle
+	 * races of where it gets disabled but we still do a record.
+	 * As the check is in the fast path of the tracers, it is more
+	 * important to be fast than accurate.
+	 */
+	tr->buffer_disabled = 0;
+	/* Make the flag seen by readers */
+	smp_wmb();
+}
+
 /**
  * tracing_on - enable tracing buffers
  *
@@ -349,15 +381,7 @@ unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
  */
 void tracing_on(void)
 {
-	if (global_trace.trace_buffer.buffer)
-		ring_buffer_record_on(global_trace.trace_buffer.buffer);
-	/*
-	 * This flag is only looked at when buffers haven't been
-	 * allocated yet. We don't really care about the race
-	 * between setting this flag and actually turning
-	 * on the buffer.
-	 */
-	global_trace.buffer_disabled = 0;
+	tracer_tracing_on(&global_trace);
 }
 EXPORT_SYMBOL_GPL(tracing_on);
 
@@ -551,6 +575,23 @@ void tracing_snapshot_alloc(void)
 EXPORT_SYMBOL_GPL(tracing_snapshot_alloc);
 #endif /* CONFIG_TRACER_SNAPSHOT */
 
+void tracer_tracing_off(struct trace_array *tr)
+{
+	if (tr->trace_buffer.buffer)
+		ring_buffer_record_off(tr->trace_buffer.buffer);
+	/*
+	 * This flag is looked at when buffers haven't been allocated
+	 * yet, or by some tracers (like irqsoff), that just want to
+	 * know if the ring buffer has been disabled, but it can handle
+	 * races of where it gets disabled but we still do a record.
+	 * As the check is in the fast path of the tracers, it is more
+	 * important to be fast than accurate.
+	 */
+	tr->buffer_disabled = 1;
+	/* Make the flag seen by readers */
+	smp_wmb();
+}
+
 /**
  * tracing_off - turn off tracing buffers
  *
@@ -561,15 +602,7 @@ EXPORT_SYMBOL_GPL(tracing_snapshot_alloc);
  */
 void tracing_off(void)
 {
-	if (global_trace.trace_buffer.buffer)
-		ring_buffer_record_off(global_trace.trace_buffer.buffer);
-	/*
-	 * This flag is only looked at when buffers haven't been
-	 * allocated yet. We don't really care about the race
-	 * between setting this flag and actually turning
-	 * on the buffer.
-	 */
-	global_trace.buffer_disabled = 1;
+	tracer_tracing_off(&global_trace);
 }
 EXPORT_SYMBOL_GPL(tracing_off);
 
@@ -580,13 +613,24 @@ void disable_trace_on_warning(void)
 }
 
 /**
+ * tracer_tracing_is_on - show real state of ring buffer enabled
+ * @tr : the trace array to know if ring buffer is enabled
+ *
+ * Shows real state of the ring buffer if it is enabled or not.
+ */
+int tracer_tracing_is_on(struct trace_array *tr)
+{
+	if (tr->trace_buffer.buffer)
+		return ring_buffer_record_is_on(tr->trace_buffer.buffer);
+	return !tr->buffer_disabled;
+}
+
+/**
  * tracing_is_on - show state of ring buffers enabled
  */
 int tracing_is_on(void)
 {
-	if (global_trace.trace_buffer.buffer)
-		return ring_buffer_record_is_on(global_trace.trace_buffer.buffer);
-	return !global_trace.buffer_disabled;
+	return tracer_tracing_is_on(&global_trace);
 }
 EXPORT_SYMBOL_GPL(tracing_is_on);
 
@@ -3958,7 +4002,7 @@ static int tracing_wait_pipe(struct file *filp)
 		 *
 		 * iter->pos will be 0 if we haven't read anything.
 		 */
-		if (!tracing_is_enabled() && iter->pos)
+		if (!tracing_is_on() && iter->pos)
 			break;
 	}
 
@@ -5631,15 +5675,10 @@ rb_simple_read(struct file *filp, char __user *ubuf,
 	       size_t cnt, loff_t *ppos)
 {
 	struct trace_array *tr = filp->private_data;
-	struct ring_buffer *buffer = tr->trace_buffer.buffer;
 	char buf[64];
 	int r;
 
-	if (buffer)
-		r = ring_buffer_record_is_on(buffer);
-	else
-		r = 0;
-
+	r = tracer_tracing_is_on(tr);
 	r = sprintf(buf, "%d\n", r);
 
 	return simple_read_from_buffer(ubuf, cnt, ppos, buf, r);
@@ -5661,11 +5700,11 @@ rb_simple_write(struct file *filp, const char __user *ubuf,
 	if (buffer) {
 		mutex_lock(&trace_types_lock);
 		if (val) {
-			ring_buffer_record_on(buffer);
+			tracer_tracing_on(tr);
 			if (tr->current_trace->start)
 				tr->current_trace->start(tr);
 		} else {
-			ring_buffer_record_off(buffer);
+			tracer_tracing_off(tr);
 			if (tr->current_trace->stop)
 				tr->current_trace->stop(tr);
 		}
kernel/trace/trace_irqsoff.c +2 -2
index b19d065..2aefbee 100644
@@ -373,7 +373,7 @@ start_critical_timing(unsigned long ip, unsigned long parent_ip)
 	struct trace_array_cpu *data;
 	unsigned long flags;
 
-	if (likely(!tracer_enabled))
+	if (!tracer_enabled || !tracing_is_enabled())
 		return;
 
 	cpu = raw_smp_processor_id();
@@ -416,7 +416,7 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip)
 	else
 		return;
 
-	if (!tracer_enabled)
+	if (!tracer_enabled || !tracing_is_enabled())
 		return;
 
 	data = per_cpu_ptr(tr->trace_buffer.data, cpu);
Signature · 1 line
1.7.10.4
author maintainer
#9 lore raw

PATCH 9/14 tracing/kprobes: Dont pass addr=ip to perf_trace_buf_submit()

In reply to Steven Rostedt

From: Oleg Nesterov <[email protected]>

kprobe_perf_func() and kretprobe_perf_func() pass addr=ip to perf_trace_buf_submit() for no reason.

This sets perf_sample_data->addr for PERF_SAMPLE_ADDR, we already have perf_sample_data->ip initialized if PERF_SAMPLE_IP.

---
 kernel/trace/trace_kprobe.c |    6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)
kernel/trace/trace_kprobe.c +2 -4
index 405b5b0..7ed6976 100644
@@ -1098,8 +1098,7 @@ kprobe_perf_func(struct trace_probe *tp, struct pt_regs *regs)
 	entry->ip = (unsigned long)tp->rp.kp.addr;
 	memset(&entry[1], 0, dsize);
 	store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);
-	perf_trace_buf_submit(entry, size, rctx,
-					entry->ip, 1, regs, head, NULL);
+	perf_trace_buf_submit(entry, size, rctx, 0, 1, regs, head, NULL);
 }
 
 /* Kretprobe profile handler */
@@ -1132,8 +1131,7 @@ kretprobe_perf_func(struct trace_probe *tp, struct kretprobe_instance *ri,
 	entry->func = (unsigned long)tp->rp.kp.addr;
 	entry->ret_ip = (unsigned long)ri->ret_addr;
 	store_trace_args(sizeof(*entry), tp, regs, (u8 *)&entry[1], dsize);
-	perf_trace_buf_submit(entry, size, rctx,
-					entry->ret_ip, 1, regs, head, NULL);
+	perf_trace_buf_submit(entry, size, rctx, 0, 1, regs, head, NULL);
 }
 #endif	/* CONFIG_PERF_EVENTS */
 
Signature · 1 line
1.7.10.4
author maintainer
#10 lore raw

PATCH 10/14 ftrace: Do not run selftest if command line parameter is set

In reply to Steven Rostedt

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

If the kernel command line ftrace filter parameters are set (ftrace_filter or ftrace_notrace), force the function self test to pass, with a warning why it was forced.

If the user adds a filter to the kernel command line, it is assumed that they know what they are doing, and the self test should just not run instead of failing (which disables function tracing) or clearing the filter, as that will probably annoy the user.

If the user wants the selftest to run, the message will tell them why it did not.

---
 kernel/trace/ftrace.c         |    5 +++++
 kernel/trace/trace.h          |    1 +
 kernel/trace/trace_selftest.c |   18 ++++++++++++++++--
 3 files changed, 22 insertions(+), 2 deletions(-)
kernel/trace/ftrace.c +5 -0
index 26e1910..67708f4 100644
@@ -3537,8 +3537,12 @@ EXPORT_SYMBOL_GPL(ftrace_set_global_notrace);
 static char ftrace_notrace_buf[FTRACE_FILTER_SIZE] __initdata;
 static char ftrace_filter_buf[FTRACE_FILTER_SIZE] __initdata;
 
+/* Used by function selftest to not test if filter is set */
+bool ftrace_filter_param __initdata;
+
 static int __init set_ftrace_notrace(char *str)
 {
+	ftrace_filter_param = true;
 	strlcpy(ftrace_notrace_buf, str, FTRACE_FILTER_SIZE);
 	return 1;
 }
@@ -3546,6 +3550,7 @@ __setup("ftrace_notrace=", set_ftrace_notrace);
 
 static int __init set_ftrace_filter(char *str)
 {
+	ftrace_filter_param = true;
 	strlcpy(ftrace_filter_buf, str, FTRACE_FILTER_SIZE);
 	return 1;
 }
kernel/trace/trace.h +1 -0
index 711ca7d..a88939e 100644
@@ -776,6 +776,7 @@ print_graph_function_flags(struct trace_iterator *iter, u32 flags)
 extern struct list_head ftrace_pids;
 
 #ifdef CONFIG_FUNCTION_TRACER
+extern bool ftrace_filter_param __initdata;
 static inline int ftrace_trace_task(struct task_struct *task)
 {
 	if (list_empty(&ftrace_pids))
kernel/trace/trace_selftest.c +16 -2
index 2901e3b..a7329b7 100644
@@ -640,13 +640,20 @@ out:
  * Enable ftrace, sleep 1/10 second, and then read the trace
  * buffer to see if all is in order.
  */
-int
+__init int
 trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
 {
 	int save_ftrace_enabled = ftrace_enabled;
 	unsigned long count;
 	int ret;
 
+#ifdef CONFIG_DYNAMIC_FTRACE
+	if (ftrace_filter_param) {
+		printk(KERN_CONT " ... kernel command line filter set: force PASS ... ");
+		return 0;
+	}
+#endif
+
 	/* make sure msleep has been recorded */
 	msleep(1);
 
@@ -727,13 +734,20 @@ static int trace_graph_entry_watchdog(struct ftrace_graph_ent *trace)
  * Pretty much the same than for the function tracer from which the selftest
  * has been borrowed.
  */
-int
+__init int
 trace_selftest_startup_function_graph(struct tracer *trace,
 					struct trace_array *tr)
 {
 	int ret;
 	unsigned long count;
 
+#ifdef CONFIG_DYNAMIC_FTRACE
+	if (ftrace_filter_param) {
+		printk(KERN_CONT " ... kernel command line filter set: force PASS ... ");
+		return 0;
+	}
+#endif
+
 	/*
 	 * Simulate the init() callback but we attach a watchdog callback
 	 * to detect and recover from possible hangs
Signature · 1 line
1.7.10.4
author maintainer
#11 lore raw

PATCH 11/14 tracing: Make trace_marker use the correct per-instance buffer

In reply to Steven Rostedt

From: Alexander Z Lam <[email protected]>

The trace_marker file was present for each new instance created, but it added the trace mark to the global trace buffer instead of to the instance's buffer.

Cc David Sharp <[email protected]>
Cc Vaibhav Nagarnaik <[email protected]>
Cc Alexander Z Lam <[email protected]>
---
 kernel/trace/trace.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)
kernel/trace/trace.c +2 -1
index 0dc5071..e04e711 100644
@@ -4391,6 +4391,7 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 					size_t cnt, loff_t *fpos)
 {
 	unsigned long addr = (unsigned long)ubuf;
+	struct trace_array *tr = filp->private_data;
 	struct ring_buffer_event *event;
 	struct ring_buffer *buffer;
 	struct print_entry *entry;
@@ -4450,7 +4451,7 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
 
 	local_save_flags(irq_flags);
 	size = sizeof(*entry) + cnt + 2; /* possible \n added */
-	buffer = global_trace.trace_buffer.buffer;
+	buffer = tr->trace_buffer.buffer;
 	event = trace_buffer_lock_reserve(buffer, TRACE_PRINT, size,
 					  irq_flags, preempt_count());
 	if (!event) {
Signature · 1 line
1.7.10.4
author maintainer
#12 lore raw

PATCH 12/14 tracing: Protect ftrace_trace_arrays list in trace_events.c

In reply to Steven Rostedt

From: Alexander Z Lam <[email protected]>

There are multiple places where the ftrace_trace_arrays list is accessed in trace_events.c without the trace_types_lock held.

Cc Vaibhav Nagarnaik <[email protected]>
Cc David Sharp <[email protected]>
Cc Alexander Z Lam <[email protected]>
---
 kernel/trace/trace.c        |    2 +-
 kernel/trace/trace.h        |    2 ++
 kernel/trace/trace_events.c |   11 ++++++++++-
 3 files changed, 13 insertions(+), 2 deletions(-)
kernel/trace/trace.c +1 -1
index e04e711..e36da7f 100644
@@ -266,7 +266,7 @@ static struct tracer		*trace_types __read_mostly;
 /*
  * trace_types_lock is used to protect the trace_types list.
  */
-static DEFINE_MUTEX(trace_types_lock);
+DEFINE_MUTEX(trace_types_lock);
 
 /*
  * serialize the access of the ring buffer
kernel/trace/trace.h +2 -0
index a88939e..2c3cba59 100644
@@ -224,6 +224,8 @@ enum {
 
 extern struct list_head ftrace_trace_arrays;
 
+extern struct mutex trace_types_lock;
+
 /*
  * The global tracer (top) should be the first trace array added,
  * but we check the flag anyway.
kernel/trace/trace_events.c +10 -1
index 5892470..35c6f23 100644
@@ -1008,6 +1008,7 @@ static int subsystem_open(struct inode *inode, struct file *filp)
 	int ret;
 
 	/* Make sure the system still exists */
+	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
 	list_for_each_entry(tr, &ftrace_trace_arrays, list) {
 		list_for_each_entry(dir, &tr->systems, list) {
@@ -1023,6 +1024,7 @@ static int subsystem_open(struct inode *inode, struct file *filp)
 	}
  exit_loop:
 	mutex_unlock(&event_mutex);
+	mutex_unlock(&trace_types_lock);
 
 	if (!system)
 		return -ENODEV;
@@ -1617,6 +1619,7 @@ static void __add_event_to_tracers(struct ftrace_event_call *call,
 int trace_add_event_call(struct ftrace_event_call *call)
 {
 	int ret;
+	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
 
 	ret = __register_event(call, NULL);
@@ -1624,11 +1627,13 @@ int trace_add_event_call(struct ftrace_event_call *call)
 		__add_event_to_tracers(call, NULL);
 
 	mutex_unlock(&event_mutex);
+	mutex_unlock(&trace_types_lock);
 	return ret;
 }
 
 /*
- * Must be called under locking both of event_mutex and trace_event_sem.
+ * Must be called under locking of trace_types_lock, event_mutex and
+ * trace_event_sem.
  */
 static void __trace_remove_event_call(struct ftrace_event_call *call)
 {
@@ -1640,11 +1645,13 @@ static void __trace_remove_event_call(struct ftrace_event_call *call)
 /* Remove an event_call */
 void trace_remove_event_call(struct ftrace_event_call *call)
 {
+	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
 	down_write(&trace_event_sem);
 	__trace_remove_event_call(call);
 	up_write(&trace_event_sem);
 	mutex_unlock(&event_mutex);
+	mutex_unlock(&trace_types_lock);
 }
 
 #define for_each_event(event, start, end)			\
@@ -1788,6 +1795,7 @@ static int trace_module_notify(struct notifier_block *self,
 {
 	struct module *mod = data;
 
+	mutex_lock(&trace_types_lock);
 	mutex_lock(&event_mutex);
 	switch (val) {
 	case MODULE_STATE_COMING:
@@ -1798,6 +1806,7 @@ static int trace_module_notify(struct notifier_block *self,
 		break;
 	}
 	mutex_unlock(&event_mutex);
+	mutex_unlock(&trace_types_lock);
 
 	return 0;
 }
Signature · 1 line
1.7.10.4
author maintainer
#13 lore raw

PATCH 13/14 tracing: Add trace_array_get/put() to handle instance refs better

In reply to Steven Rostedt

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

Commit a695cb58162 "tracing: Prevent deleting instances when they are being read" tried to fix a race between deleting a trace instance and reading contents of a trace file. But it wasn't good enough. The following could crash the kernel:

 # cd /sys/kernel/debug/tracing/instances
 # ( while :; do mkdir foo; rmdir foo; done ) &
 # ( while :; do cat foo/trace &> /dev/null; done ) &

Luckily this can only be done by root user, but it should be fixed regardless.

The problem is that a delete of the file can happen after the reader starts to open the file but before it grabs the trace_types_mutex.

The solution is to validate the trace array before using it. If the trace array does not exist in the list of trace arrays, then it returns -ENODEV.

There's a possibility that a trace_array could be deleted and a new one created and the open would open its file instead. But that is very minor as it will just return the data of the new trace array, it may confuse the user but it will not crash the system. As this can only be done by root anyway, the race will only occur if root is deleting what its trying to read at the same time.

---
 kernel/trace/trace.c |   83 +++++++++++++++++++++++++++++++++++++++-----------
 1 file changed, 65 insertions(+), 18 deletions(-)
kernel/trace/trace.c +65 -18
index e36da7f..6be9df1 100644
@@ -204,6 +204,37 @@ static struct trace_array	global_trace;
 
 LIST_HEAD(ftrace_trace_arrays);
 
+int trace_array_get(struct trace_array *this_tr)
+{
+	struct trace_array *tr;
+	int ret = -ENODEV;
+
+	mutex_lock(&trace_types_lock);
+	list_for_each_entry(tr, &ftrace_trace_arrays, list) {
+		if (tr == this_tr) {
+			tr->ref++;
+			ret = 0;
+			break;
+		}
+	}
+	mutex_unlock(&trace_types_lock);
+
+	return ret;
+}
+
+static void __trace_array_put(struct trace_array *this_tr)
+{
+	WARN_ON(!this_tr->ref);
+	this_tr->ref--;
+}
+
+void trace_array_put(struct trace_array *this_tr)
+{
+	mutex_lock(&trace_types_lock);
+	__trace_array_put(this_tr);
+	mutex_unlock(&trace_types_lock);
+}
+
 int filter_current_check_discard(struct ring_buffer *buffer,
 				 struct ftrace_event_call *call, void *rec,
 				 struct ring_buffer_event *event)
@@ -2831,10 +2862,9 @@ static const struct seq_operations tracer_seq_ops = {
 };
 
 static struct trace_iterator *
-__tracing_open(struct inode *inode, struct file *file, bool snapshot)
+__tracing_open(struct trace_array *tr, struct trace_cpu *tc,
+	       struct inode *inode, struct file *file, bool snapshot)
 {
-	struct trace_cpu *tc = inode->i_private;
-	struct trace_array *tr = tc->tr;
 	struct trace_iterator *iter;
 	int cpu;
 
@@ -2913,8 +2943,6 @@ __tracing_open(struct inode *inode, struct file *file, bool snapshot)
 		tracing_iter_reset(iter, cpu);
 	}
 
-	tr->ref++;
-
 	mutex_unlock(&trace_types_lock);
 
 	return iter;
@@ -2944,17 +2972,20 @@ static int tracing_release(struct inode *inode, struct file *file)
 	struct trace_array *tr;
 	int cpu;
 
-	if (!(file->f_mode & FMODE_READ))
+	/* Writes do not use seq_file, need to grab tr from inode */
+	if (!(file->f_mode & FMODE_READ)) {
+		struct trace_cpu *tc = inode->i_private;
+
+		trace_array_put(tc->tr);
 		return 0;
+	}
 
 	iter = m->private;
 	tr = iter->tr;
+	trace_array_put(tr);
 
 	mutex_lock(&trace_types_lock);
 
-	WARN_ON(!tr->ref);
-	tr->ref--;
-
 	for_each_tracing_cpu(cpu) {
 		if (iter->buffer_iter[cpu])
 			ring_buffer_read_finish(iter->buffer_iter[cpu]);
@@ -2973,20 +3004,23 @@ static int tracing_release(struct inode *inode, struct file *file)
 	kfree(iter->trace);
 	kfree(iter->buffer_iter);
 	seq_release_private(inode, file);
+
 	return 0;
 }
 
 static int tracing_open(struct inode *inode, struct file *file)
 {
+	struct trace_cpu *tc = inode->i_private;
+	struct trace_array *tr = tc->tr;
 	struct trace_iterator *iter;
 	int ret = 0;
 
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
 	/* If this file was open for write, then erase contents */
 	if ((file->f_mode & FMODE_WRITE) &&
 	    (file->f_flags & O_TRUNC)) {
-		struct trace_cpu *tc = inode->i_private;
-		struct trace_array *tr = tc->tr;
-
 		if (tc->cpu == RING_BUFFER_ALL_CPUS)
 			tracing_reset_online_cpus(&tr->trace_buffer);
 		else
@@ -2994,12 +3028,16 @@ static int tracing_open(struct inode *inode, struct file *file)
 	}
 
 	if (file->f_mode & FMODE_READ) {
-		iter = __tracing_open(inode, file, false);
+		iter = __tracing_open(tr, tc, inode, file, false);
 		if (IS_ERR(iter))
 			ret = PTR_ERR(iter);
 		else if (trace_flags & TRACE_ITER_LATENCY_FMT)
 			iter->iter_flags |= TRACE_FILE_LAT_FMT;
 	}
+
+	if (ret < 0)
+		trace_array_put(tr);
+
 	return ret;
 }
 
@@ -4575,12 +4613,16 @@ struct ftrace_buffer_info {
 static int tracing_snapshot_open(struct inode *inode, struct file *file)
 {
 	struct trace_cpu *tc = inode->i_private;
+	struct trace_array *tr = tc->tr;
 	struct trace_iterator *iter;
 	struct seq_file *m;
 	int ret = 0;
 
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
 	if (file->f_mode & FMODE_READ) {
-		iter = __tracing_open(inode, file, true);
+		iter = __tracing_open(tr, tc, inode, file, true);
 		if (IS_ERR(iter))
 			ret = PTR_ERR(iter);
 	} else {
@@ -4593,13 +4635,16 @@ static int tracing_snapshot_open(struct inode *inode, struct file *file)
 			kfree(m);
 			return -ENOMEM;
 		}
-		iter->tr = tc->tr;
+		iter->tr = tr;
 		iter->trace_buffer = &tc->tr->max_buffer;
 		iter->cpu_file = tc->cpu;
 		m->private = iter;
 		file->private_data = m;
 	}
 
+	if (ret < 0)
+		trace_array_put(tr);
+
 	return ret;
 }
 
@@ -4680,9 +4725,12 @@ out:
 static int tracing_snapshot_release(struct inode *inode, struct file *file)
 {
 	struct seq_file *m = file->private_data;
+	int ret;
+
+	ret = tracing_release(inode, file);
 
 	if (file->f_mode & FMODE_READ)
-		return tracing_release(inode, file);
+		return ret;
 
 	/* If write only, the seq_file is just a stub */
 	if (m)
@@ -4927,8 +4975,7 @@ static int tracing_buffers_release(struct inode *inode, struct file *file)
 
 	mutex_lock(&trace_types_lock);
 
-	WARN_ON(!iter->tr->ref);
-	iter->tr->ref--;
+	__trace_array_put(iter->tr);
 
 	if (info->spare)
 		ring_buffer_free_read_page(iter->trace_buffer->buffer, info->spare);
Signature · 1 line
1.7.10.4
author maintainer
#14 lore raw

PATCH 14/14 tracing: Get trace_array ref counts when accessing trace files

In reply to Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

---
 kernel/trace/trace.c |  121 ++++++++++++++++++++++++++++++++++++++++++++++----
 1 file changed, 112 insertions(+), 9 deletions(-)
kernel/trace/trace.c +112 -9
index 6be9df1..6d9bd9b 100644
@@ -2965,6 +2965,43 @@ int tracing_open_generic(struct inode *inode, struct file *filp)
 	return 0;
 }
 
+/*
+ * Open and update trace_array ref count.
+ * Must have the current trace_array passed to it.
+ */
+int tracing_open_generic_tr(struct inode *inode, struct file *filp)
+{
+	struct trace_array *tr = inode->i_private;
+
+	if (tracing_disabled)
+		return -ENODEV;
+
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
+	filp->private_data = inode->i_private;
+
+	return 0;
+	
+}
+
+int tracing_open_generic_tc(struct inode *inode, struct file *filp)
+{
+	struct trace_cpu *tc = inode->i_private;
+	struct trace_array *tr = tc->tr;
+
+	if (tracing_disabled)
+		return -ENODEV;
+
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
+	filp->private_data = inode->i_private;
+
+	return 0;
+	
+}
+
 static int tracing_release(struct inode *inode, struct file *file)
 {
 	struct seq_file *m = file->private_data;
@@ -3008,6 +3045,32 @@ static int tracing_release(struct inode *inode, struct file *file)
 	return 0;
 }
 
+static int tracing_release_generic_tr(struct inode *inode, struct file *file)
+{
+	struct trace_array *tr = inode->i_private;
+
+	trace_array_put(tr);
+	return 0;
+}
+
+static int tracing_release_generic_tc(struct inode *inode, struct file *file)
+{
+	struct trace_cpu *tc = inode->i_private;
+	struct trace_array *tr = tc->tr;
+
+	trace_array_put(tr);
+	return 0;
+}
+
+static int tracing_single_release_tr(struct inode *inode, struct file *file)
+{
+	struct trace_array *tr = inode->i_private;
+
+	trace_array_put(tr);
+
+	return single_release(inode, file);
+}
+
 static int tracing_open(struct inode *inode, struct file *file)
 {
 	struct trace_cpu *tc = inode->i_private;
@@ -3394,9 +3457,14 @@ tracing_trace_options_write(struct file *filp, const char __user *ubuf,
 
 static int tracing_trace_options_open(struct inode *inode, struct file *file)
 {
+	struct trace_array *tr = inode->i_private;
+
 	if (tracing_disabled)
 		return -ENODEV;
 
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
 	return single_open(file, tracing_trace_options_show, inode->i_private);
 }
 
@@ -3404,7 +3472,7 @@ static const struct file_operations tracing_iter_fops = {
 	.open		= tracing_trace_options_open,
 	.read		= seq_read,
 	.llseek		= seq_lseek,
-	.release	= single_release,
+	.release	= tracing_single_release_tr,
 	.write		= tracing_trace_options_write,
 };
 
@@ -3892,6 +3960,9 @@ static int tracing_open_pipe(struct inode *inode, struct file *filp)
 	if (tracing_disabled)
 		return -ENODEV;
 
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
 	mutex_lock(&trace_types_lock);
 
 	/* create a buffer to store the information to pass to userspace */
@@ -3944,6 +4015,7 @@ out:
 fail:
 	kfree(iter->trace);
 	kfree(iter);
+	__trace_array_put(tr);
 	mutex_unlock(&trace_types_lock);
 	return ret;
 }
@@ -3951,6 +4023,8 @@ fail:
 static int tracing_release_pipe(struct inode *inode, struct file *file)
 {
 	struct trace_iterator *iter = file->private_data;
+	struct trace_cpu *tc = inode->i_private;
+	struct trace_array *tr = tc->tr;
 
 	mutex_lock(&trace_types_lock);
 
@@ -3964,6 +4038,8 @@ static int tracing_release_pipe(struct inode *inode, struct file *file)
 	kfree(iter->trace);
 	kfree(iter);
 
+	trace_array_put(tr);
+
 	return 0;
 }
 
@@ -4421,6 +4497,8 @@ tracing_free_buffer_release(struct inode *inode, struct file *filp)
 	/* resize the ring buffer to 0 */
 	tracing_resize_ring_buffer(tr, 0, RING_BUFFER_ALL_CPUS);
 
+	trace_array_put(tr);
+
 	return 0;
 }
 
@@ -4597,10 +4675,20 @@ static ssize_t tracing_clock_write(struct file *filp, const char __user *ubuf,
 
 static int tracing_clock_open(struct inode *inode, struct file *file)
 {
+	struct trace_array *tr = inode->i_private;
+	int ret;
+
 	if (tracing_disabled)
 		return -ENODEV;
 
-	return single_open(file, tracing_clock_show, inode->i_private);
+	if (trace_array_get(tr))
+		return -ENODEV;
+
+	ret = single_open(file, tracing_clock_show, inode->i_private);
+	if (ret < 0)
+		trace_array_put(tr);
+
+	return ret;
 }
 
 struct ftrace_buffer_info {
@@ -4796,34 +4884,38 @@ static const struct file_operations tracing_pipe_fops = {
 };
 
 static const struct file_operations tracing_entries_fops = {
-	.open		= tracing_open_generic,
+	.open		= tracing_open_generic_tc,
 	.read		= tracing_entries_read,
 	.write		= tracing_entries_write,
 	.llseek		= generic_file_llseek,
+	.release	= tracing_release_generic_tc,
 };
 
 static const struct file_operations tracing_total_entries_fops = {
-	.open		= tracing_open_generic,
+	.open		= tracing_open_generic_tr,
 	.read		= tracing_total_entries_read,
 	.llseek		= generic_file_llseek,
+	.release	= tracing_release_generic_tr,
 };
 
 static const struct file_operations tracing_free_buffer_fops = {
+	.open		= tracing_open_generic_tr,
 	.write		= tracing_free_buffer_write,
 	.release	= tracing_free_buffer_release,
 };
 
 static const struct file_operations tracing_mark_fops = {
-	.open		= tracing_open_generic,
+	.open		= tracing_open_generic_tr,
 	.write		= tracing_mark_write,
 	.llseek		= generic_file_llseek,
+	.release	= tracing_release_generic_tr,
 };
 
 static const struct file_operations trace_clock_fops = {
 	.open		= tracing_clock_open,
 	.read		= seq_read,
 	.llseek		= seq_lseek,
-	.release	= single_release,
+	.release	= tracing_single_release_tr,
 	.write		= tracing_clock_write,
 };
 
@@ -4851,13 +4943,19 @@ static int tracing_buffers_open(struct inode *inode, struct file *filp)
 	struct trace_cpu *tc = inode->i_private;
 	struct trace_array *tr = tc->tr;
 	struct ftrace_buffer_info *info;
+	int ret;
 
 	if (tracing_disabled)
 		return -ENODEV;
 
+	if (trace_array_get(tr) < 0)
+		return -ENODEV;
+
 	info = kzalloc(sizeof(*info), GFP_KERNEL);
-	if (!info)
+	if (!info) {
+		trace_array_put(tr);
 		return -ENOMEM;
+	}
 
 	mutex_lock(&trace_types_lock);
 
@@ -4875,7 +4973,11 @@ static int tracing_buffers_open(struct inode *inode, struct file *filp)
 
 	mutex_unlock(&trace_types_lock);
 
-	return nonseekable_open(inode, filp);
+	ret = nonseekable_open(inode, filp);
+	if (ret < 0)
+		trace_array_put(tr);
+
+	return ret;
 }
 
 static unsigned int
@@ -5765,9 +5867,10 @@ rb_simple_write(struct file *filp, const char __user *ubuf,
 }
 
 static const struct file_operations rb_simple_fops = {
-	.open		= tracing_open_generic,
+	.open		= tracing_open_generic_tr,
 	.read		= rb_simple_read,
 	.write		= rb_simple_write,
+	.release	= tracing_release_generic_tr,
 	.llseek		= default_llseek,
 };
 
Signature · 1 line
1.7.10.4
#15 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Hi Steven,

This patch seems to cause the following lockdep warning:

[ 5644.288019] ======================================================
[ 5644.288771] [ INFO: possible circular locking dependency detected ]
[ 5644.289657] 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 Not tainted
[ 5644.290568] -------------------------------------------------------
[ 5644.290783] trinity-c17/19105 is trying to acquire lock:
[ 5644.290783] (trace_types_lock){+.+.+.}, at: trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783]
[ 5644.290783] but task is already holding lock:
[ 5644.290783] (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] which lock already depends on the new lock.
[ 5644.290783]
[ 5644.290783]
[ 5644.290783] the existing dependency chain (in reverse order) is:
[ 5644.290783]
-> #2 (&sig->cred_guard_mutex){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_interruptible_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:616)
[ 5644.290783] proc_pid_attr_write (fs/proc/base.c:2250)
[ 5644.290783] __kernel_write (fs/read_write.c:457)
[ 5644.290783] write_pipe_buf (fs/splice.c:1072)
[ 5644.290783] splice_from_pipe_feed (fs/splice.c:834)
[ 5644.290783] __splice_from_pipe (fs/splice.c:955)
[ 5644.290783] splice_from_pipe (fs/splice.c:990)
[ 5644.290783] default_file_splice_write (fs/splice.c:1084)
[ 5644.290783] SyS_splice (include/linux/fs.h:2333 fs/splice.c:1391 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] tracesys (arch/x86/kernel/entry_64.S:749)
[ 5644.290783]
-> #1 (&pipe->mutex/1){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] pipe_lock_nested (fs/pipe.c:61)
[ 5644.290783] pipe_lock (fs/pipe.c:69)
[ 5644.290783] splice_to_pipe (include/linux/wait.h:103 fs/splice.c:247)
[ 5644.290783] tracing_buffers_splice_read (kernel/trace/trace.c:5423)
[ 5644.290783] do_splice_to (fs/splice.c:1151)
[ 5644.290783] SyS_splice (fs/splice.c:1416 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] ia32_sysret (arch/x86/ia32/ia32entry.S:430)
[ 5644.290783]
-> #0 (trace_types_lock){+.+.+.}:
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
[ 5644.290783]
[ 5644.290783] other info that might help us debug this:
[ 5644.290783]
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)

Thanks,
Sasha

author maintainer
#16 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 6 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 5 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Quoted 8 lines
Quoted 3 lines

Hi Steven,

This patch seems to cause the following lockdep warning:

Thanks for the update. I run all my tests with lockdep enabled. I'm wondering if your config enable a lock that I don't have in my configs. Could you send me your .config please.

Thanks!

-- Steve

#17 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 13 lines · Steven Rostedt
Quoted 10 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Quoted 8 lines
Quoted 4 lines

Hi Steven,

This patch seems to cause the following lockdep warning:

Thanks for the update. I run all my tests with lockdep enabled. I'm wondering if your config enable a lock that I don't have in my configs. Could you send me your .config please.

Attached.

Thanks,
Sasha

author maintainer
#18 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 6 lines · On Sat, 05 Apr 2014 16:03:13 -0400 Sasha Levin <[email protected]> wrote:
Quoted 3 lines

Thanks for the update. I run all my tests with lockdep enabled. I'm wondering if your config enable a lock that I don't have in my configs. Could you send me your .config please.

Attached.

Do you have any other configs that trigger this? This config is a monster and after I finally did get it to install, it just locked up on boot, with no messages.

-- Steve

#19 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 7 lines · Steven Rostedt
Quoted 4 lines · On Sat, 05 Apr 2014 16:03:13 -0400 Sasha Levin <[email protected]> wrote:
Quoted 3 lines

Thanks for the update. I run all my tests with lockdep enabled. I'm wondering if your config enable a lock that I don't have in my configs. Could you send me your .config please.

Quoted 6 lines
Quoted 2 lines

Attached.

Do you have any other configs that trigger this? This config is a monster and after I finally did get it to install, it just locked up on boot, with no messages.

Not really, that's the only one I use for fuzzing.

I'm running it in a vm, so maybe it's worth trying that?

Thanks,
Sasha

author maintainer
#20 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

In reply to Sasha Levin
Quoted 11 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);

Or I haven't done enough to trigger both paths in a single boot :-/

Anyway, I'm questioning the trace_types_lock being held throughout the entire path of tracing_buffers_splice_read(). I'll have to look deeper into this on Monday. If we can fine grain that lock in that function it may get us out of this potential deadlock.

Thanks for reporting.

-- Steve

Quoted 49 lines
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)

Thanks,
Sasha

author maintainer
#21 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

In reply to Sasha Levin
Quoted 119 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Hi Steven,

This patch seems to cause the following lockdep warning:

[ 5644.288019] ======================================================
[ 5644.288771] [ INFO: possible circular locking dependency detected ]
[ 5644.289657] 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 Not tainted
[ 5644.290568] -------------------------------------------------------
[ 5644.290783] trinity-c17/19105 is trying to acquire lock:
[ 5644.290783] (trace_types_lock){+.+.+.}, at: trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783]
[ 5644.290783] but task is already holding lock:
[ 5644.290783] (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] which lock already depends on the new lock.
[ 5644.290783]
[ 5644.290783]
[ 5644.290783] the existing dependency chain (in reverse order) is:
[ 5644.290783]
-> #2 (&sig->cred_guard_mutex){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_interruptible_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:616)
[ 5644.290783] proc_pid_attr_write (fs/proc/base.c:2250)
[ 5644.290783] __kernel_write (fs/read_write.c:457)
[ 5644.290783] write_pipe_buf (fs/splice.c:1072)
[ 5644.290783] splice_from_pipe_feed (fs/splice.c:834)
[ 5644.290783] __splice_from_pipe (fs/splice.c:955)
[ 5644.290783] splice_from_pipe (fs/splice.c:990)
[ 5644.290783] default_file_splice_write (fs/splice.c:1084)
[ 5644.290783] SyS_splice (include/linux/fs.h:2333 fs/splice.c:1391 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] tracesys (arch/x86/kernel/entry_64.S:749)
[ 5644.290783]
-> #1 (&pipe->mutex/1){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] pipe_lock_nested (fs/pipe.c:61)
[ 5644.290783] pipe_lock (fs/pipe.c:69)
[ 5644.290783] splice_to_pipe (include/linux/wait.h:103 fs/splice.c:247)
[ 5644.290783] tracing_buffers_splice_read (kernel/trace/trace.c:5423)
[ 5644.290783] do_splice_to (fs/splice.c:1151)
[ 5644.290783] SyS_splice (fs/splice.c:1416 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] ia32_sysret (arch/x86/ia32/ia32entry.S:430)
[ 5644.290783]
-> #0 (trace_types_lock){+.+.+.}:
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
[ 5644.290783]
[ 5644.290783] other info that might help us debug this:
[ 5644.290783]
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
Quoted 9 lines
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)

Wait a minute! The syscall is a compat_SyS_execve, which does an do_execve_common, which does a do_open_exec, which ends up opening a tracing file????

How the hell did that happen. Is your tool execing files in the tracing directory? I wonder if that's even possible, and if so, how can we prevent that? The trace_pipe file (which is what uses the tracing_open_pipe) is set to rrr. No exec should be allowed.

-- Steve

#22 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 132 lines · Steven Rostedt
Quoted 119 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Hi Steven,

This patch seems to cause the following lockdep warning:

[ 5644.288019] ======================================================
[ 5644.288771] [ INFO: possible circular locking dependency detected ]
[ 5644.289657] 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 Not tainted
[ 5644.290568] -------------------------------------------------------
[ 5644.290783] trinity-c17/19105 is trying to acquire lock:
[ 5644.290783] (trace_types_lock){+.+.+.}, at: trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783]
[ 5644.290783] but task is already holding lock:
[ 5644.290783] (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] which lock already depends on the new lock.
[ 5644.290783]
[ 5644.290783]
[ 5644.290783] the existing dependency chain (in reverse order) is:
[ 5644.290783]
-> #2 (&sig->cred_guard_mutex){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_interruptible_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:616)
[ 5644.290783] proc_pid_attr_write (fs/proc/base.c:2250)
[ 5644.290783] __kernel_write (fs/read_write.c:457)
[ 5644.290783] write_pipe_buf (fs/splice.c:1072)
[ 5644.290783] splice_from_pipe_feed (fs/splice.c:834)
[ 5644.290783] __splice_from_pipe (fs/splice.c:955)
[ 5644.290783] splice_from_pipe (fs/splice.c:990)
[ 5644.290783] default_file_splice_write (fs/splice.c:1084)
[ 5644.290783] SyS_splice (include/linux/fs.h:2333 fs/splice.c:1391 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] tracesys (arch/x86/kernel/entry_64.S:749)
[ 5644.290783]
-> #1 (&pipe->mutex/1){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] pipe_lock_nested (fs/pipe.c:61)
[ 5644.290783] pipe_lock (fs/pipe.c:69)
[ 5644.290783] splice_to_pipe (include/linux/wait.h:103 fs/splice.c:247)
[ 5644.290783] tracing_buffers_splice_read (kernel/trace/trace.c:5423)
[ 5644.290783] do_splice_to (fs/splice.c:1151)
[ 5644.290783] SyS_splice (fs/splice.c:1416 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] ia32_sysret (arch/x86/ia32/ia32entry.S:430)
[ 5644.290783]
-> #0 (trace_types_lock){+.+.+.}:
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
[ 5644.290783]
[ 5644.290783] other info that might help us debug this:
[ 5644.290783]
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
Quoted 9 lines
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
Quoted 8 lines

Wait a minute! The syscall is a compat_SyS_execve, which does an do_execve_common, which does a do_open_exec, which ends up opening a tracing file????

How the hell did that happen. Is your tool execing files in the tracing directory? I wonder if that's even possible, and if so, how can we prevent that? The trace_pipe file (which is what uses the tracing_open_pipe) is set to rrr. No exec should be allowed.

It could happen easily manually:

# ls -al trace_pipe
-r--r--r-- 1 root 0 0 Apr  8 16:43 trace_pipe
# chmod 777 trace_pipe
# ls -al trace_pipe
-rwxrwxrwx 1 root 0 0 Apr  8 16:43 trace_pipe
# ./trace_pipe

Although when I mount everything for the fuzzer I do it with '-onoexec,nosuid' and the fuzzer is banned from testing mount(), so I'm not sure how it would do that thing on it's own.

Thanks,
Sasha

author maintainer
#23 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 142 lines · On Tue, 08 Apr 2014 12:52:04 -0400 Sasha Levin <[email protected]> wrote:
Quoted 132 lines · Steven Rostedt
Quoted 119 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Hi Steven,

This patch seems to cause the following lockdep warning:

[ 5644.288019] ======================================================
[ 5644.288771] [ INFO: possible circular locking dependency detected ]
[ 5644.289657] 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 Not tainted
[ 5644.290568] -------------------------------------------------------
[ 5644.290783] trinity-c17/19105 is trying to acquire lock:
[ 5644.290783] (trace_types_lock){+.+.+.}, at: trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783]
[ 5644.290783] but task is already holding lock:
[ 5644.290783] (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] which lock already depends on the new lock.
[ 5644.290783]
[ 5644.290783]
[ 5644.290783] the existing dependency chain (in reverse order) is:
[ 5644.290783]
-> #2 (&sig->cred_guard_mutex){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_interruptible_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:616)
[ 5644.290783] proc_pid_attr_write (fs/proc/base.c:2250)
[ 5644.290783] __kernel_write (fs/read_write.c:457)
[ 5644.290783] write_pipe_buf (fs/splice.c:1072)
[ 5644.290783] splice_from_pipe_feed (fs/splice.c:834)
[ 5644.290783] __splice_from_pipe (fs/splice.c:955)
[ 5644.290783] splice_from_pipe (fs/splice.c:990)
[ 5644.290783] default_file_splice_write (fs/splice.c:1084)
[ 5644.290783] SyS_splice (include/linux/fs.h:2333 fs/splice.c:1391 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] tracesys (arch/x86/kernel/entry_64.S:749)
[ 5644.290783]
-> #1 (&pipe->mutex/1){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] pipe_lock_nested (fs/pipe.c:61)
[ 5644.290783] pipe_lock (fs/pipe.c:69)
[ 5644.290783] splice_to_pipe (include/linux/wait.h:103 fs/splice.c:247)
[ 5644.290783] tracing_buffers_splice_read (kernel/trace/trace.c:5423)
[ 5644.290783] do_splice_to (fs/splice.c:1151)
[ 5644.290783] SyS_splice (fs/splice.c:1416 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] ia32_sysret (arch/x86/ia32/ia32entry.S:430)
[ 5644.290783]
-> #0 (trace_types_lock){+.+.+.}:
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
[ 5644.290783]
[ 5644.290783] other info that might help us debug this:
[ 5644.290783]
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
Quoted 9 lines
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
Quoted 8 lines

Wait a minute! The syscall is a compat_SyS_execve, which does an do_execve_common, which does a do_open_exec, which ends up opening a tracing file????

How the hell did that happen. Is your tool execing files in the tracing directory? I wonder if that's even possible, and if so, how can we prevent that? The trace_pipe file (which is what uses the tracing_open_pipe) is set to rrr. No exec should be allowed.

Quoted 8 lines

It could happen easily manually:

# ls -al trace_pipe
-r--r--r-- 1 root 0 0 Apr  8 16:43 trace_pipe
# chmod 777 trace_pipe
# ls -al trace_pipe
-rwxrwxrwx 1 root 0 0 Apr  8 16:43 trace_pipe
# ./trace_pipe

I wonder if there's a way to prevent a debugfs file from having its permissions changed.

Quoted 4 lines

Although when I mount everything for the fuzzer I do it with '-onoexec,nosuid' and the fuzzer is banned from testing mount(), so I'm not sure how it would do that thing on it's own.

What does the -onoexec do? Not change the exec flag of files?

Also, I wonder if this has something to do with the syscall being a compat sys_exec and not a native one. Is userspace on your vm 32bit? Or does the fuzzer just try the different compat calls?

-- Steve

#24 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 158 lines · Steven Rostedt
Quoted 142 lines · On Tue, 08 Apr 2014 12:52:04 -0400 Sasha Levin <[email protected]> wrote:
Quoted 132 lines · Steven Rostedt
Quoted 119 lines · On Sat, 05 Apr 2014 10:59:10 -0400 Sasha Levin <[email protected]> wrote:
Quoted 8 lines · Steven Rostedt

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

When a trace file is opened that may access a trace array, it must increment its ref count to prevent it from being deleted.

Hi Steven,

This patch seems to cause the following lockdep warning:

[ 5644.288019] ======================================================
[ 5644.288771] [ INFO: possible circular locking dependency detected ]
[ 5644.289657] 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 Not tainted
[ 5644.290568] -------------------------------------------------------
[ 5644.290783] trinity-c17/19105 is trying to acquire lock:
[ 5644.290783] (trace_types_lock){+.+.+.}, at: trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783]
[ 5644.290783] but task is already holding lock:
[ 5644.290783] (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] which lock already depends on the new lock.
[ 5644.290783]
[ 5644.290783]
[ 5644.290783] the existing dependency chain (in reverse order) is:
[ 5644.290783]
-> #2 (&sig->cred_guard_mutex){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_interruptible_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:616)
[ 5644.290783] proc_pid_attr_write (fs/proc/base.c:2250)
[ 5644.290783] __kernel_write (fs/read_write.c:457)
[ 5644.290783] write_pipe_buf (fs/splice.c:1072)
[ 5644.290783] splice_from_pipe_feed (fs/splice.c:834)
[ 5644.290783] __splice_from_pipe (fs/splice.c:955)
[ 5644.290783] splice_from_pipe (fs/splice.c:990)
[ 5644.290783] default_file_splice_write (fs/splice.c:1084)
[ 5644.290783] SyS_splice (include/linux/fs.h:2333 fs/splice.c:1391 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] tracesys (arch/x86/kernel/entry_64.S:749)
[ 5644.290783]
-> #1 (&pipe->mutex/1){+.+.+.}:
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] pipe_lock_nested (fs/pipe.c:61)
[ 5644.290783] pipe_lock (fs/pipe.c:69)
[ 5644.290783] splice_to_pipe (include/linux/wait.h:103 fs/splice.c:247)
[ 5644.290783] tracing_buffers_splice_read (kernel/trace/trace.c:5423)
[ 5644.290783] do_splice_to (fs/splice.c:1151)
[ 5644.290783] SyS_splice (fs/splice.c:1416 fs/splice.c:1764 fs/splice.c:1749)
[ 5644.290783] ia32_sysret (arch/x86/ia32/ia32entry.S:430)
[ 5644.290783]
-> #0 (trace_types_lock){+.+.+.}:
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
[ 5644.290783]
[ 5644.290783] other info that might help us debug this:
[ 5644.290783]
[ 5644.290783] Chain exists of:

trace_types_lock --> &pipe->mutex/1 --> &sig->cred_guard_mutex

[ 5644.290783]  Possible unsafe locking scenario:
[ 5644.290783]
[ 5644.290783]        CPU0                    CPU1
[ 5644.290783]        ----                    ----
[ 5644.290783]   lock(&sig->cred_guard_mutex);
[ 5644.290783]                                lock(&pipe->mutex/1);
[ 5644.290783]                                lock(&sig->cred_guard_mutex);
[ 5644.290783]   lock(trace_types_lock);
[ 5644.290783]
[ 5644.290783]  *** DEADLOCK ***
[ 5644.290783]
[ 5644.290783] 1 lock held by trinity-c17/19105:
[ 5644.290783] #0: (&sig->cred_guard_mutex){+.+.+.}, at: prepare_bprm_creds (fs/exec.c:1165)
[ 5644.290783]
[ 5644.290783] stack backtrace:
[ 5644.290783] CPU: 10 PID: 19105 Comm: trinity-c17 Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376
[ 5644.290783]  ffffffffb4a1a1e0 ffff88071a7738f8 ffffffffb14bfb2f 0000000000000000
[ 5644.290783]  ffffffffb49a9dd0 ffff88071a773948 ffffffffb14b2527 0000000000000001
[ 5644.290783]  ffff88071a7739d8 ffff88071a773948 ffff8805d98cbcf0 ffff8805d98cbd28
[ 5644.290783] Call Trace:
[ 5644.290783] dump_stack (lib/dump_stack.c:52)
[ 5644.290783] print_circular_bug (kernel/locking/lockdep.c:1214)
[ 5644.290783] __lock_acquire (kernel/locking/lockdep.c:1840 kernel/locking/lockdep.c:1945 kernel/locking/lockdep.c:2131 kernel/locking/lockdep.c:3182)
[ 5644.290783] ? _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:809 include/linux/spinlock_api_smp.h:160 kernel/locking/spinlock.c:191)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] ? __slab_free (mm/slub.c:2598)
[ 5644.290783] lock_acquire (arch/x86/include/asm/current.h:14 kernel/locking/lockdep.c:3602)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] mutex_lock_nested (kernel/locking/mutex.c:486 kernel/locking/mutex.c:587)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? locks_free_lock (fs/locks.c:244)
[ 5644.290783] ? trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] ? preempt_count_sub (kernel/sched/core.c:2527)
[ 5644.290783] trace_array_get (kernel/trace/trace.c:225)
[ 5644.290783] tracing_open_generic_tr (kernel/trace/trace.c:3053)
[ 5644.290783] do_dentry_open (fs/open.c:753)
[ 5644.290783] ? tracing_open_pipe (kernel/trace/trace.c:3047)
[ 5644.290783] finish_open (fs/open.c:818)
[ 5644.290783] do_last (fs/namei.c:3040)
[ 5644.290783] ? link_path_walk (fs/namei.c:1473 fs/namei.c:1744)
[ 5644.290783] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[ 5644.290783] ? trace_hardirqs_on_caller (kernel/locking/lockdep.c:2557 kernel/locking/lockdep.c:2599)
[ 5644.290783] path_openat (fs/namei.c:3182)
[ 5644.290783] ? __lock_acquire (kernel/locking/lockdep.c:3189)
[ 5644.290783] do_filp_open (fs/namei.c:3231)
Quoted 9 lines
[ 5644.290783] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254)
[ 5644.290783] ? do_execve_common.isra.19 (fs/exec.c:1489)
[ 5644.290783] ? get_parent_ip (kernel/sched/core.c:2472)
[ 5644.290783] do_open_exec (fs/exec.c:766)
[ 5644.290783] do_execve_common.isra.19 (fs/exec.c:1491)
[ 5644.290783] ? do_execve_common.isra.19 (include/linux/spinlock.h:303 fs/exec.c:1258 fs/exec.c:1486)
[ 5644.290783] compat_SyS_execve (fs/exec.c:1627)
[ 5644.290783] ia32_ptregs_common (arch/x86/ia32/ia32entry.S:495)
Quoted 8 lines

Wait a minute! The syscall is a compat_SyS_execve, which does an do_execve_common, which does a do_open_exec, which ends up opening a tracing file????

How the hell did that happen. Is your tool execing files in the tracing directory? I wonder if that's even possible, and if so, how can we prevent that? The trace_pipe file (which is what uses the tracing_open_pipe) is set to rrr. No exec should be allowed.

Quoted 8 lines

It could happen easily manually:

# ls -al trace_pipe
-r--r--r-- 1 root 0 0 Apr  8 16:43 trace_pipe
# chmod 777 trace_pipe
# ls -al trace_pipe
-rwxrwxrwx 1 root 0 0 Apr  8 16:43 trace_pipe
# ./trace_pipe

I wonder if there's a way to prevent a debugfs file from having its permissions changed.

Quoted 1 line
Quoted 5 lines
Quoted 3 lines

Although when I mount everything for the fuzzer I do it with '-onoexec,nosuid' and the fuzzer is banned from testing mount(), so I'm not sure how it would do that thing on it's own.

What does the -onoexec do? Not change the exec flag of files?

It lets you set it as executable, but it won't let you actually exec it.

Quoted 3 lines

Also, I wonder if this has something to do with the syscall being a compat sys_exec and not a native one. Is userspace on your vm 32bit? Or does the fuzzer just try the different compat calls?

Right, everything is 64bit but the fuzzer tries 32bit calls as well.

Thanks,
Sasha

author maintainer
#25 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 7 lines · On Tue, 08 Apr 2014 13:11:32 -0400 Sasha Levin <[email protected]> wrote:
Quoted 6 lines
Quoted 4 lines

Although when I mount everything for the fuzzer I do it with '-onoexec,nosuid' and the fuzzer is banned from testing mount(), so I'm not sure how it would do that thing on it's own.

What does the -onoexec do? Not change the exec flag of files?

Quoted 7 lines

It lets you set it as executable, but it won't let you actually exec it.

Quoted 3 lines

Also, I wonder if this has something to do with the syscall being a compat sys_exec and not a native one. Is userspace on your vm 32bit? Or does the fuzzer just try the different compat calls?

Right, everything is 64bit but the fuzzer tries 32bit calls as well.

When this bug is triggered, is there a way to let the fuzzer tell us what exactly the last syscall it sent was? That is, the syscall number plus all its arguments?

-- Steve

author maintainer
#26 lore raw

Re: [for-next][PATCH 14/14] tracing: Get trace_array ref counts when accessing trace files

Quoted 16 lines · On Tue, 8 Apr 2014 13:32:31 -0400 Steven Rostedt <[email protected]> wrote:
Quoted 13 lines · On Tue, 08 Apr 2014 13:11:32 -0400 Sasha Levin <[email protected]> wrote:
Quoted 6 lines
Quoted 4 lines

Although when I mount everything for the fuzzer I do it with '-onoexec,nosuid' and the fuzzer is banned from testing mount(), so I'm not sure how it would do that thing on it's own.

What does the -onoexec do? Not change the exec flag of files?

It lets you set it as executable, but it won't let you actually exec it.

Quoted 3 lines

Also, I wonder if this has something to do with the syscall being a compat sys_exec and not a native one. Is userspace on your vm 32bit? Or does the fuzzer just try the different compat calls?

Quoted 5 lines
Quoted 1 line

Right, everything is 64bit but the fuzzer tries 32bit calls as well.

When this bug is triggered, is there a way to let the fuzzer tell us what exactly the last syscall it sent was? That is, the syscall number plus all its arguments?

Just letting you know. I'm holding off looking too deep into this as it seems to require very strange behavior to trigger (like perhaps execing a tracing file). This only happens when running as root, right? If not, then there's a bigger bug involved.

If you can get me more information on this bug, like what I suggested above, then I'll take another look.

Thanks,

-- Steve