Skip to contentSkip to conversation

tracing: fixes and documentation updates

GIT PULL In review Steven Rostedt 4 participants 11 messages Jan 26, 2010 – Jan 27, 2010

Subsystems (4)
lore
Share & tools
lore

Steven Rostedt

author maintainer
#0 lore raw

Ingo,

I found that reading the trace file and the raw_trace_pipe using splice, at the same time could cause a kernel oops. Not a major one, that is, the oops only crashes the user task that is performing the read of the trace file. But still urgent enough to go into 2.6.33.

The issue is with the iterator that is stored to access multiple reads of the ring buffer without consuming the data. If a user process starts reading the contents of the ring buffer with the iterator, and in the mean time a consuming read is done, then the iterator can become stale and return a bogus entry.

The first patch fixes the pid to cmdline mapping function to not crash when given a negative pid (which happened when we had a bogus entry).

The next two patches fix the ring buffer to detect when a consuming read is done and to reset the iterator.

Since I'm pushing these patches up, I've also incuded two documentation changes. One of the patches touches a Kconfig file but only the help portion of it.

Please pull the latest tip/tracing/urgent tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/tracing/urgent

Mike Frysinger (1):
tracing/documentation: Cover new frame pointer semantics

Steven Rostedt (3):
tracing: Prevent kernel oops with corrupted buffer
ring-buffer: Check if ring buffer iterator has stale data
ring-buffer: Check for end of page in iterator

Yang Hongyang (1):
tracing/documentation: Fix a typo in ftrace.txt

----

 Documentation/trace/ftrace-design.txt |   26 +++++++++++++++++++++++---
 Documentation/trace/ftrace.txt        |    2 +-
 kernel/trace/Kconfig                  |    4 +---
 kernel/trace/ring_buffer.c            |   24 +++++++++++++++++++++---
 kernel/trace/trace.c                  |    5 +++++
 5 files changed, 51 insertions(+), 10 deletions(-)
author maintainer
#1 lore raw

PATCH 1/5 tracing: Prevent kernel oops with corrupted buffer

From: Steven Rostedt <[email protected]>

If the contents of the ftrace ring buffer gets corrupted and the trace file is read, it could create a kernel oops (usualy just killing the user task thread). This is caused by the checking of the pid in the buffer. If the pid is negative, it still references the cmdline cache array, which could point to an invalid address.

The simple fix is to test for negative PIDs.

---
 kernel/trace/trace.c |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)
kernel/trace/trace.c +5 -0
index 0df1b0f..eac6875 100644
@@ -951,6 +951,11 @@ void trace_find_cmdline(int pid, char comm[])
 		return;
 	}
 
+	if (WARN_ON_ONCE(pid < 0)) {
+		strcpy(comm, "<XXX>");
+		return;
+	}
+
 	if (pid > PID_MAX_DEFAULT) {
 		strcpy(comm, "<...>");
 		return;
Signature · 1 line
1.6.5
#2 lore raw

Re: [PATCH 1/5] tracing: Prevent kernel oops with corrupted buffer

Quoted 4 lines · On Tue, 26 Jan 2010 17:09:24 -0500 Steven Rostedt <[email protected]> wrote:

From: Steven Rostedt <[email protected]>

If the contents of the ftrace ring buffer gets corrupted and the trace file is read, it could create a kernel oops (usualy just killing the user

"usually" ;)

Quoted 17 lines

task thread). This is caused by the checking of the pid in the buffer. If the pid is negative, it still references the cmdline cache array, which could point to an invalid address.

The simple fix is to test for negative PIDs.

---
 kernel/trace/trace.c |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)
kernel/trace/trace.c +0 -0
index 0df1b0f..eac6875 100644
@@ -951,6 +951,11 @@ void trace_find_cmdline(int pid, char comm[])
 		return;

kernel/trace/trace.c void trace_find_cmdline(int pid, char comm[]) · line 961

Quoted 10 lines
kernel/trace/trace.c +5 -0
 	}
 
+	if (WARN_ON_ONCE(pid < 0)) {
+		strcpy(comm, "<XXX>");
+		return;
+	}
+
 	if (pid > PID_MAX_DEFAULT) {
 		strcpy(comm, "<...>");
 		return;

But why is it WARN_ON_ONCE()? That will only fix the problem a single time. On the second occurrence, it will oops again.

#3 lore raw

Re: [PATCH 1/5] tracing: Prevent kernel oops with corrupted buffer

Quoted 11 lines · Andrew Morton

kernel/trace/trace.c void trace_find_cmdline(int pid, char comm[]) · line 961

Quoted 8 lines
kernel/trace/trace.c +5 -0
+	if (WARN_ON_ONCE(pid < 0)) {
+		strcpy(comm, "<XXX>");
+		return;
+	}
+
 	if (pid > PID_MAX_DEFAULT) {
 		strcpy(comm, "<...>");
 		return;

But why is it WARN_ON_ONCE()? That will only fix the problem a single time. On the second occurrence, it will oops again.

The warning will be produced only once, but after that, the condition is still checked like a simple if:

#define WARN_ON_ONCE(condition)	({				\
	static bool __warned;					\
	int __ret_warn_once = !!(condition);			\
								\
	if (unlikely(__ret_warn_once))				\
		if (WARN_ON(!__warned)) 			\
			__warned = true;			\
	unlikely(__ret_warn_once);				\
})

And since this function can be called anytime we have a trace to print to the user, we don't want to encumber with thousands of warnings.

author maintainer
#4 lore raw

Re: [PATCH 1/5] tracing: Prevent kernel oops with corrupted buffer

Quoted 29 lines · Frederic Weisbecker
Quoted 11 lines · Andrew Morton

kernel/trace/trace.c void trace_find_cmdline(int pid, char comm[]) · line 961

Quoted 8 lines
kernel/trace/trace.c +5 -0
+	if (WARN_ON_ONCE(pid < 0)) {
+		strcpy(comm, "<XXX>");
+		return;
+	}
+
 	if (pid > PID_MAX_DEFAULT) {
 		strcpy(comm, "<...>");
 		return;

But why is it WARN_ON_ONCE()? That will only fix the problem a single time. On the second occurrence, it will oops again.

The warning will be produced only once, but after that, the condition is still checked like a simple if:

#define WARN_ON_ONCE(condition)	({				\
	static bool __warned;					\
	int __ret_warn_once = !!(condition);			\
								\
	if (unlikely(__ret_warn_once))				\
		if (WARN_ON(!__warned)) 			\
			__warned = true;			\
	unlikely(__ret_warn_once);				\
})
Quoted 3 lines

And since this function can be called anytime we have a trace to print to the user, we don't want to encumber with thousands of warnings.

Exactly!

-- Steve

author maintainer
#5 lore raw

Re: [PATCH 1/5] tracing: Prevent kernel oops with corrupted buffer

In reply to Andrew Morton
Quoted 9 lines · Andrew Morton
Quoted 4 lines · On Tue, 26 Jan 2010 17:09:24 -0500 Steven Rostedt <[email protected]> wrote:

From: Steven Rostedt <[email protected]>

If the contents of the ftrace ring buffer gets corrupted and the trace file is read, it could create a kernel oops (usualy just killing the user

"usually" ;)

I used "usually" since that is what happened every time I encountered the issue. But I don't know 100% if it only oops the user task in every instance.

Quoted 20 lines
Quoted 20 lines

task thread). This is caused by the checking of the pid in the buffer. If the pid is negative, it still references the cmdline cache array, which could point to an invalid address.

The simple fix is to test for negative PIDs.

---
 kernel/trace/trace.c |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)
kernel/trace/trace.c +0 -0
index 0df1b0f..eac6875 100644
@@ -951,6 +951,11 @@ void trace_find_cmdline(int pid, char comm[])
 		return;
 	}
 
Quoted 11 lines

kernel/trace/trace.c void trace_find_cmdline(int pid, char comm[]) · line 961

Quoted 8 lines
kernel/trace/trace.c +5 -0
+	if (WARN_ON_ONCE(pid < 0)) {
+		strcpy(comm, "<XXX>");
+		return;
+	}
+
 	if (pid > PID_MAX_DEFAULT) {
 		strcpy(comm, "<...>");
 		return;

But why is it WARN_ON_ONCE()? That will only fix the problem a single time. On the second occurrence, it will oops again.

Frederic correctly answered this.

Thanks,

-- Steve

author maintainer
#6 lore raw

PATCH 2/5 ring-buffer: Check if ring buffer iterator has stale data

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

Usually reads of the ring buffer is performed by a single task. There are two types of reads from the ring buffer.

One is a consuming read which will consume the entry that was read and the next read will be the entry that follows.

The other is an iterator that will let the user read the contents of the ring buffer without modifying it. When an iterator is allocated, writes to the ring buffer are disabled to protect the iterator.

The problem exists when consuming reads happen while an iterator is allocated. Specifically, the kind of read that swaps out an entire page (used by splice) and replaces it with a new read. If the iterator is on the page that is swapped out, then the next read may read from this swapped out page and return garbage.

This patch adds a check when reading the iterator to make sure that the iterator contents are still valid. If a consuming read has taken place, the iterator is reset.

---
 kernel/trace/ring_buffer.c |   13 +++++++++++++
 1 files changed, 13 insertions(+), 0 deletions(-)
kernel/trace/ring_buffer.c +13 -0
index edefe3b..503b630 100644
@@ -464,6 +464,8 @@ struct ring_buffer_iter {
 	struct ring_buffer_per_cpu	*cpu_buffer;
 	unsigned long			head;
 	struct buffer_page		*head_page;
+	struct buffer_page		*cache_reader_page;
+	unsigned long			cache_read;
 	u64				read_stamp;
 };
 
@@ -2716,6 +2718,8 @@ static void rb_iter_reset(struct ring_buffer_iter *iter)
 		iter->read_stamp = cpu_buffer->read_stamp;
 	else
 		iter->read_stamp = iter->head_page->page->time_stamp;
+	iter->cache_reader_page = cpu_buffer->reader_page;
+	iter->cache_read = cpu_buffer->read;
 }
 
 /**
@@ -3066,6 +3070,15 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 	cpu_buffer = iter->cpu_buffer;
 	buffer = cpu_buffer->buffer;
 
+	/*
+	 * Check if someone performed a consuming read to
+	 * the buffer. A consuming read invalidates the iterator
+	 * and we need to reset the iterator in this case.
+	 */
+	if (unlikely(iter->cache_read != cpu_buffer->read ||
+		     iter->cache_reader_page != cpu_buffer->reader_page))
+		rb_iter_reset(iter);
+
  again:
 	/*
 	 * We repeat when a timestamp is encountered.
Signature · 1 line
1.6.5
author maintainer
#7 lore raw

PATCH 3/5 ring-buffer: Check for end of page in iterator

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

If the iterator comes to an empty page for some reason, or if the page is emptied by a consuming read. The iterator code currently does not check if the iterator is pass the contents, and may return a false entry.

This patch adds a check to the ring buffer iterator to test if the current page has been completely read and sets the iterator to the next page if necessary.

---
 kernel/trace/ring_buffer.c |   11 ++++++++---
 1 files changed, 8 insertions(+), 3 deletions(-)
kernel/trace/ring_buffer.c +8 -3
index 503b630..8c1b2d2 100644
@@ -3064,9 +3064,6 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 	struct ring_buffer_event *event;
 	int nr_loops = 0;
 
-	if (ring_buffer_iter_empty(iter))
-		return NULL;
-
 	cpu_buffer = iter->cpu_buffer;
 	buffer = cpu_buffer->buffer;
 
@@ -3080,6 +3077,9 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 		rb_iter_reset(iter);
 
  again:
+	if (ring_buffer_iter_empty(iter))
+		return NULL;
+
 	/*
 	 * We repeat when a timestamp is encountered.
 	 * We can get multiple timestamps by nested interrupts or also
@@ -3094,6 +3094,11 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 	if (rb_per_cpu_empty(cpu_buffer))
 		return NULL;
 
+	if (iter->head >= local_read(&iter->head_page->page->commit)) {
+		rb_inc_iter(iter);
+		goto again;
+	}
+
 	event = rb_iter_head_event(iter);
 
 	switch (event->type_len) {
Signature · 1 line
1.6.5
author maintainer
#8 lore raw

PATCH 4/5 tracing/documentation: Fix a typo in ftrace.txt

In reply to Steven Rostedt

From: Yang Hongyang <[email protected]>

'ftrace' is no longer the name of the function tracer, to activate the function trace 'echo function > current_tracer' is to be used instead of 'echo ftrace > current_tracer'. Update the documentation to reflect the current implementation.

LKML-Reference: <[email protected]>

---
 Documentation/trace/ftrace.txt |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)
Documentation/trace/ftrace.txt +1 -1
index 8179692..bab3040 100644
@@ -1625,7 +1625,7 @@ If I am only interested in sys_nanosleep and hrtimer_interrupt:
 
  # echo sys_nanosleep hrtimer_interrupt \
 		> set_ftrace_filter
- # echo ftrace > current_tracer
+ # echo function > current_tracer
  # echo 1 > tracing_enabled
  # usleep 1
  # echo 0 > tracing_enabled
Signature · 1 line
1.6.5
author maintainer
#9 lore raw

PATCH 5/5 tracing/documentation: Cover new frame pointer semantics

In reply to Steven Rostedt

From: Mike Frysinger <[email protected]>

Update the graph tracer examples to cover the new frame pointer semantics (in terms of passing it along). Move the HAVE_FUNCTION_GRAPH_FP_TEST docs out of the Kconfig, into the right place, and expand on the details.

LKML-Reference: <[email protected]>

---
 Documentation/trace/ftrace-design.txt |   26 +++++++++++++++++++++++---
 kernel/trace/Kconfig                  |    4 +---
 2 files changed, 24 insertions(+), 6 deletions(-)
Documentation/trace/ftrace-design.txt +23 -3
index 239f14b..6a5a579 100644
@@ -1,5 +1,6 @@
 		function tracer guts
 		====================
+		By Mike Frysinger
 
 Introduction
 ------------
@@ -173,14 +174,16 @@ void ftrace_graph_caller(void)
 
 	unsigned long *frompc = &...;
 	unsigned long selfpc = <return address> - MCOUNT_INSN_SIZE;
-	prepare_ftrace_return(frompc, selfpc);
+	/* passing frame pointer up is optional -- see below */
+	prepare_ftrace_return(frompc, selfpc, frame_pointer);
 
 	/* restore all state needed by the ABI */
 }
 #endif
 
-For information on how to implement prepare_ftrace_return(), simply look at
-the x86 version.  The only architecture-specific piece in it is the setup of
+For information on how to implement prepare_ftrace_return(), simply look at the
+x86 version (the frame pointer passing is optional; see the next section for
+more information).  The only architecture-specific piece in it is the setup of
 the fault recovery table (the asm(...) code).  The rest should be the same
 across architectures.
 
@@ -205,6 +208,23 @@ void return_to_handler(void)
 #endif
 
 
+HAVE_FUNCTION_GRAPH_FP_TEST
+---------------------------
+
+An arch may pass in a unique value (frame pointer) to both the entering and
+exiting of a function.  On exit, the value is compared and if it does not
+match, then it will panic the kernel.  This is largely a sanity check for bad
+code generation with gcc.  If gcc for your port sanely updates the frame
+pointer under different opitmization levels, then ignore this option.
+
+However, adding support for it isn't terribly difficult.  In your assembly code
+that calls prepare_ftrace_return(), pass the frame pointer as the 3rd argument.
+Then in the C version of that function, do what the x86 port does and pass it
+along to ftrace_push_return_trace() instead of a stub value of 0.
+
+Similarly, when you call ftrace_return_to_handler(), pass it the frame pointer.
+
+
 HAVE_FTRACE_NMI_ENTER
 ---------------------
 
kernel/trace/Kconfig +1 -3
index 6c22d8a..60e2ce0 100644
@@ -27,9 +27,7 @@ config HAVE_FUNCTION_GRAPH_TRACER
 config HAVE_FUNCTION_GRAPH_FP_TEST
 	bool
 	help
-	 An arch may pass in a unique value (frame pointer) to both the
-	 entering and exiting of a function. On exit, the value is compared
-	 and if it does not match, then it will panic the kernel.
+	  See Documentation/trace/ftrace-design.txt
 
 config HAVE_FUNCTION_TRACE_MCOUNT_TEST
 	bool
Signature · 1 line
1.6.5
#10 lore raw
In reply to Steven Rostedt
Quoted 40 lines · Steven Rostedt

Ingo,

I found that reading the trace file and the raw_trace_pipe using splice, at the same time could cause a kernel oops. Not a major one, that is, the oops only crashes the user task that is performing the read of the trace file. But still urgent enough to go into 2.6.33.

The issue is with the iterator that is stored to access multiple reads of the ring buffer without consuming the data. If a user process starts reading the contents of the ring buffer with the iterator, and in the mean time a consuming read is done, then the iterator can become stale and return a bogus entry.

The first patch fixes the pid to cmdline mapping function to not crash when given a negative pid (which happened when we had a bogus entry).

The next two patches fix the ring buffer to detect when a consuming read is done and to reset the iterator.

Since I'm pushing these patches up, I've also incuded two documentation changes. One of the patches touches a Kconfig file but only the help portion of it.

Please pull the latest tip/tracing/urgent tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/tracing/urgent

Mike Frysinger (1):
tracing/documentation: Cover new frame pointer semantics

Steven Rostedt (3):
tracing: Prevent kernel oops with corrupted buffer
ring-buffer: Check if ring buffer iterator has stale data
ring-buffer: Check for end of page in iterator

Yang Hongyang (1):
tracing/documentation: Fix a typo in ftrace.txt

Quoted 7 lines

----

 Documentation/trace/ftrace-design.txt |   26 +++++++++++++++++++++++---
 Documentation/trace/ftrace.txt        |    2 +-
 kernel/trace/Kconfig                  |    4 +---
 kernel/trace/ring_buffer.c            |   24 +++++++++++++++++++++---
 kernel/trace/trace.c                  |    5 +++++
 5 files changed, 51 insertions(+), 10 deletions(-)

Pulled, thanks a lot Steve!

Ingo