[for-next][PATCH 00/14] tracing: updates and fixes for 3.10

[for-next][PATCH 00/14] tracing: updates and fixes for 3.10

[Steven Rostedt]

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

[for-next][PATCH 01/14] tracing: Failed to create system directory

[Steven Rostedt]

[-- Attachment #1: 0001-tracing-Failed-to-create-system-directory.patch --]
[-- Type: text/plain, Size: 4589 bytes --]

From: Steven Rostedt <rostedt@goodmis.org>

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.

Cc: stable@vger.kernel.org # 3.10
Reported-by: "zhangwei(Jovi)" <jovi.zhangwei@huawei.com>
Reported-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Tested-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_events.c |   41 +++++++++++++++++++++++++++++++++++------
 1 file changed, 35 insertions(+), 6 deletions(-)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index f57b015..903a0bf 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -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;
 }
-- 
1.7.10.4

[for-next][PATCH 02/14] tracing/kprobes: Avoid perf_trace_buf_*() if ->perf_events is empty

[Steven Rostedt]

[-- Attachment #1: 0002-tracing-kprobes-Avoid-perf_trace_buf_-if-perf_events.patch --]
[-- Type: text/plain, Size: 2459 bytes --]

From: Oleg Nesterov <oleg@redhat.com>

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

Link: http://lkml.kernel.org/r/20130620173806.GA13151@redhat.com

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Oleg Nesterov <oleg@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_kprobe.c |   12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index f237417..c35bebe 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -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);
 }
-- 
1.7.10.4

[for-next][PATCH 03/14] tracing/kprobes: Kill probe_enable_lock

[Steven Rostedt]

[-- Attachment #1: 0003-tracing-kprobes-Kill-probe_enable_lock.patch --]
[-- Type: text/plain, Size: 4527 bytes --]

From: Oleg Nesterov <oleg@redhat.com>

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.

Link: http://lkml.kernel.org/r/20130620173809.GA13158@redhat.com

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Oleg Nesterov <oleg@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_kprobe.c |   43 ++++++++++++++++++++-----------------------
 1 file changed, 20 insertions(+), 23 deletions(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index c35bebe..282f86c 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -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;
-- 
1.7.10.4

[for-next][PATCH 04/14] tracing: Simplify code for showing of soft disabled flag

[Steven Rostedt]

[-- Attachment #1: 0004-tracing-Simplify-code-for-showing-of-soft-disabled-f.patch --]
[-- Type: text/plain, Size: 1521 bytes --]

From: Tom Zanussi <tom.zanussi@linux.intel.com>

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.

Link: http://lkml.kernel.org/r/9aff5af6dee2f5a40ca30df41c39d5f33e998d7a.1372479499.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_events.c |   20 ++++++++++----------
 1 file changed, 10 insertions(+), 10 deletions(-)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 903a0bf..7ee08b9 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -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));
 }
-- 
1.7.10.4

[for-next][PATCH 05/14] tracing: Add missing syscall_metadata comment

[Steven Rostedt]

[-- Attachment #1: 0005-tracing-Add-missing-syscall_metadata-comment.patch --]
[-- Type: text/plain, Size: 921 bytes --]

From: Tom Zanussi <tom.zanussi@intel.com>

Add the missing syscall_metadata description for the enter_fields
struct member.

Link: http://lkml.kernel.org/r/74c3407cd1e5d37f2c5aaca637aa4d35f66f1aa2.1372479499.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi <tom.zanussi@intel.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 include/trace/syscall.h |    1 +
 1 file changed, 1 insertion(+)

diff --git a/include/trace/syscall.h b/include/trace/syscall.h
index 84bc419..fed853f 100644
--- a/include/trace/syscall.h
+++ b/include/trace/syscall.h
@@ -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
  */
-- 
1.7.10.4

[for-next][PATCH 06/14] tracing: Fix disabling of soft disable

[Steven Rostedt]

[-- Attachment #1: 0006-tracing-Fix-disabling-of-soft-disable.patch --]
[-- Type: text/plain, Size: 1570 bytes --]

From: Tom Zanussi <tom.zanussi@linux.intel.com>

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.

Link: http://lkml.kernel.org/r/b9c68dd50bc07019e6c67d3f9b29be4ef1b2badb.1372479499.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_events.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 7ee08b9..5892470 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -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:
 		/*
-- 
1.7.10.4

[for-next][PATCH 07/14] tracing/kprobes: Turn trace_probe->files into list_head

[Steven Rostedt]

[-- Attachment #1: 0007-tracing-kprobes-Turn-trace_probe-files-into-list_hea.patch --]
[-- Type: text/plain, Size: 6635 bytes --]

From: Oleg Nesterov <oleg@redhat.com>

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.

Link: http://lkml.kernel.org/r/20130620173814.GA13165@redhat.com

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Oleg Nesterov <oleg@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_kprobe.c |  138 ++++++++++++-------------------------------
 1 file changed, 37 insertions(+), 101 deletions(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index 282f86c..405b5b0 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -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 */
-- 
1.7.10.4

[for-next][PATCH 08/14] tracing: Use flag buffer_disabled for irqsoff tracer

[Steven Rostedt]

[-- Attachment #1: 0008-tracing-Use-flag-buffer_disabled-for-irqsoff-tracer.patch --]
[-- Type: text/plain, Size: 7207 bytes --]

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

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.

Reported-by: Dave Jones <davej@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c         |  101 +++++++++++++++++++++++++++++-------------
 kernel/trace/trace_irqsoff.c |    4 +-
 2 files changed, 72 insertions(+), 33 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index c4c9296..0dc5071 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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);
 		}
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index b19d065..2aefbee 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -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);
-- 
1.7.10.4

[for-next][PATCH 09/14] tracing/kprobes: Dont pass addr=ip to perf_trace_buf_submit()

[Steven Rostedt]

[-- Attachment #1: 0009-tracing-kprobes-Don-t-pass-addr-ip-to-perf_trace_buf.patch --]
[-- Type: text/plain, Size: 1582 bytes --]

From: Oleg Nesterov <oleg@redhat.com>

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.

Link: http://lkml.kernel.org/r/20130620173811.GA13161@redhat.com

Signed-off-by: Oleg Nesterov <oleg@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_kprobe.c |    6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index 405b5b0..7ed6976 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -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 */
 
-- 
1.7.10.4

[for-next][PATCH 10/14] ftrace: Do not run selftest if command line parameter is set

[Steven Rostedt]

[-- Attachment #1: 0010-ftrace-Do-not-run-selftest-if-command-line-parameter.patch --]
[-- Type: text/plain, Size: 3429 bytes --]

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

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.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ftrace.c         |    5 +++++
 kernel/trace/trace.h          |    1 +
 kernel/trace/trace_selftest.c |   18 ++++++++++++++++--
 3 files changed, 22 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 26e1910..67708f4 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -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;
 }
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 711ca7d..a88939e 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -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))
diff --git a/kernel/trace/trace_selftest.c b/kernel/trace/trace_selftest.c
index 2901e3b..a7329b7 100644
--- a/kernel/trace/trace_selftest.c
+++ b/kernel/trace/trace_selftest.c
@@ -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
-- 
1.7.10.4

[for-next][PATCH 11/14] tracing: Make trace_marker use the correct per-instance buffer

[Steven Rostedt]

[-- Attachment #1: 0011-tracing-Make-trace_marker-use-the-correct-per-instan.patch --]
[-- Type: text/plain, Size: 1460 bytes --]

From: Alexander Z Lam <azl@google.com>

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.

Link: http://lkml.kernel.org/r/1372717885-4543-2-git-send-email-azl@google.com

Cc: David Sharp <dhsharp@google.com>
Cc: Vaibhav Nagarnaik <vnagarnaik@google.com>
Cc: Alexander Z Lam <lambchop468@gmail.com>
Cc: stable@vger.kernel.org # 3.10
Signed-off-by: Alexander Z Lam <azl@google.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0dc5071..e04e711 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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) {
-- 
1.7.10.4

[for-next][PATCH 12/14] tracing: Protect ftrace_trace_arrays list in trace_events.c

[Steven Rostedt]

[-- Attachment #1: 0012-tracing-Protect-ftrace_trace_arrays-list-in-trace_ev.patch --]
[-- Type: text/plain, Size: 3739 bytes --]

From: Alexander Z Lam <azl@google.com>

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

Link: http://lkml.kernel.org/r/1372732674-22726-1-git-send-email-azl@google.com

Cc: Vaibhav Nagarnaik <vnagarnaik@google.com>
Cc: David Sharp <dhsharp@google.com>
Cc: Alexander Z Lam <lambchop468@gmail.com>
Cc: stable@vger.kernel.org # 3.10
Signed-off-by: Alexander Z Lam <azl@google.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c        |    2 +-
 kernel/trace/trace.h        |    2 ++
 kernel/trace/trace_events.c |   11 ++++++++++-
 3 files changed, 13 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index e04e711..e36da7f 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index a88939e..2c3cba59 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -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.
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 5892470..35c6f23 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -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;
 }
-- 
1.7.10.4

[for-next][PATCH 13/14] tracing: Add trace_array_get/put() to handle instance refs better

[Steven Rostedt]

[-- Attachment #1: 0013-tracing-Add-trace_array_get-put-to-handle-instance-r.patch --]
[-- Type: text/plain, Size: 6431 bytes --]

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

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.

Cc: stable@vger.kernel.org # 3.10
Reported-by: Alexander Lam <azl@google.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |   83 +++++++++++++++++++++++++++++++++++++++-----------
 1 file changed, 65 insertions(+), 18 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index e36da7f..6be9df1 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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);
-- 
1.7.10.4

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

[Steven Rostedt]

[-- Attachment #1: 0014-tracing-Get-trace_array-ref-counts-when-accessing-tr.patch --]
[-- Type: text/plain, Size: 7063 bytes --]

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

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

Cc: stable@vger.kernel.org # 3.10
Reported-by: Alexander Lam <azl@google.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace.c |  121 ++++++++++++++++++++++++++++++++++++++++++++++----
 1 file changed, 112 insertions(+), 9 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 6be9df1..6d9bd9b 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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,
 };
 
-- 
1.7.10.4

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

[Sasha Levin]

On 07/02/2013 04:22 PM, Steven Rostedt wrote:
> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
> 
> When a trace file is opened that may access a trace array, it must
> increment its ref count to prevent it from being deleted.
> 
> Cc: stable@vger.kernel.org # 3.10
> Reported-by: Alexander Lam <azl@google.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

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

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

[Steven Rostedt]

On Sat, 05 Apr 2014 10:59:10 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:

> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
> > From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
> > 
> > When a trace file is opened that may access a trace array, it must
> > increment its ref count to prevent it from being deleted.
> > 
> > Cc: stable@vger.kernel.org # 3.10
> > Reported-by: Alexander Lam <azl@google.com>
> > Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> 
> 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

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

[Sasha Levin]

[-- Attachment #1: Type: text/plain, Size: 822 bytes --]

On 04/05/2014 02:33 PM, Steven Rostedt wrote:
> On Sat, 05 Apr 2014 10:59:10 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
> 
>> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
>>> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
>>>
>>> When a trace file is opened that may access a trace array, it must
>>> increment its ref count to prevent it from being deleted.
>>>
>>> Cc: stable@vger.kernel.org # 3.10
>>> Reported-by: Alexander Lam <azl@google.com>
>>> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
>>
>> 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


[-- Attachment #2: config-sasha.gz --]
[-- Type: application/gzip, Size: 39819 bytes --]

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

[Steven Rostedt]

On Sat, 05 Apr 2014 16:03:13 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:
 
> > 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

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

[Sasha Levin]

On 04/08/2014 11:42 AM, Steven Rostedt wrote:
> On Sat, 05 Apr 2014 16:03:13 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
>  
>>> 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.

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

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

[Steven Rostedt]

On Sat, 05 Apr 2014 10:59:10 -0400
Sasha Levin <sasha.levin@oracle.com> 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

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

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

[Steven Rostedt]

On Sat, 05 Apr 2014 10:59:10 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:

> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
> > From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
> > 
> > When a trace file is opened that may access a trace array, it must
> > increment its ref count to prevent it from being deleted.
> > 
> > Cc: stable@vger.kernel.org # 3.10
> > Reported-by: Alexander Lam <azl@google.com>
> > Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> 
> 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)
> 

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

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

[Sasha Levin]

On 04/08/2014 12:36 PM, Steven Rostedt wrote:
> On Sat, 05 Apr 2014 10:59:10 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
> 
>> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
>>> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
>>>
>>> When a trace file is opened that may access a trace array, it must
>>> increment its ref count to prevent it from being deleted.
>>>
>>> Cc: stable@vger.kernel.org # 3.10
>>> Reported-by: Alexander Lam <azl@google.com>
>>> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
>>
>> 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)
>>
> 
> 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

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

[Steven Rostedt]

On Tue, 08 Apr 2014 12:52:04 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:

> On 04/08/2014 12:36 PM, Steven Rostedt wrote:
> > On Sat, 05 Apr 2014 10:59:10 -0400
> > Sasha Levin <sasha.levin@oracle.com> wrote:
> > 
> >> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
> >>> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
> >>>
> >>> When a trace file is opened that may access a trace array, it must
> >>> increment its ref count to prevent it from being deleted.
> >>>
> >>> Cc: stable@vger.kernel.org # 3.10
> >>> Reported-by: Alexander Lam <azl@google.com>
> >>> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> >>
> >> 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)
> >>
> > 
> > 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

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

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

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

[Sasha Levin]

On 04/08/2014 01:06 PM, Steven Rostedt wrote:
> On Tue, 08 Apr 2014 12:52:04 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
> 
>> On 04/08/2014 12:36 PM, Steven Rostedt wrote:
>>> On Sat, 05 Apr 2014 10:59:10 -0400
>>> Sasha Levin <sasha.levin@oracle.com> wrote:
>>>
>>>> On 07/02/2013 04:22 PM, Steven Rostedt wrote:
>>>>> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
>>>>>
>>>>> When a trace file is opened that may access a trace array, it must
>>>>> increment its ref count to prevent it from being deleted.
>>>>>
>>>>> Cc: stable@vger.kernel.org # 3.10
>>>>> Reported-by: Alexander Lam <azl@google.com>
>>>>> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
>>>>
>>>> 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)
>>>>
>>>
>>> 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
> 
> I wonder if there's a way to prevent a debugfs file from having its
> permissions changed.
> 
>>
>> 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.

> 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

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

[Steven Rostedt]

On Tue, 08 Apr 2014 13:11:32 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:

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

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

[Steven Rostedt]

On Tue, 8 Apr 2014 13:32:31 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Tue, 08 Apr 2014 13:11:32 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
> 
> > >>
> > >> 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.
> > 
> > > 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?

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