[PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[Steven Rostedt]

Linus,

This includes fixes for seq_buf_bprintf() truncation issue. It also
contains fixes to ftrace when /proc/sys/kernel/ftrace_enabled and
function tracing are started. Doing the following causes some issues:

 # echo 0 > /proc/sys/kernel/ftrace_enabled
 # echo function_graph > /sys/kernel/debug/tracing/current_tracer
 # echo 1 > /proc/sys/kernel/ftrace_enabled
 # echo nop > /sys/kernel/debug/tracing/current_tracer
 # echo function_graph > /sys/kernel/debug/tracing/current_tracer

As well as with function tracing too. Pratyush Anand first reported
this issue to me and supplied a patch. When I tested this on my x86
test box, it caused thousands of backtraces and warnings to appear in
dmesg, which also caused a denial of service (a warning for every
function that was listed). I applied Pratyush's patch but it did not
fix the issue for me. I looked into it and found a slight problem
with trampoline accounting. I fixed it and sent Pratyush a patch, but
he said that it did not fix the issue for him.

I later learned tha Pratyush was using an ARM64 server, and when I tested
on my ARM board, I was able to reproduce the same issue as Pratyush.
After applying his patch, it fixed the problem. The above test uncovered
two different bugs, one in x86 and one in ARM and ARM64. As this looked
like it would affect PowerPC, I tested it on my PPC64 box. It too broke,
but neither the patch that fixed ARM or x86 fixed this box (the changes
were all in generic code!). The above test, uncovered two more bugs that
affected PowerPC. Again, the changes were only done to generic code.
It's the way the arch code expected things to be done that was different
between the archs. Some where more sensitive than others.

The rest of this series fixes the PPC bugs as well.

This is on top of the last pull request I sent out. But doesn't seem to
have been pulled.

Please pull the latest trace-fixes-v4.0-rc2-2 tree, which can be found at:


  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
trace-fixes-v4.0-rc2-2

Tag SHA1: 5b136f3e4bf380f18402f3354cd13f9f0ffbeb02
Head SHA1: 524a38682573b2e15ab6317ccfe50280441514be


Pratyush Anand (1):
      ftrace: Fix en(dis)able graph caller when en(dis)abling record via sysctl

Steven Rostedt (Red Hat) (4):
      seq_buf: Fix seq_buf_vprintf() truncation
      seq_buf: Fix seq_buf_bprintf() truncation
      ftrace: Clear REGS_EN and TRAMP_EN flags on disabling record via sysctl
      ftrace: Fix ftrace enable ordering of sysctl ftrace_enabled

----
 kernel/trace/ftrace.c | 40 ++++++++++++++++++++++++++++++----------
 lib/seq_buf.c         |  4 ++--
 2 files changed, 32 insertions(+), 12 deletions(-)

[PATCH 1/5] seq_buf: Fix seq_buf_vprintf() truncation

[Steven Rostedt]

[-- Attachment #1: 0001-seq_buf-Fix-seq_buf_vprintf-truncation.patch --]
[-- Type: text/plain, Size: 1878 bytes --]

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

In seq_buf_vprintf(), vsnprintf() is used to copy the format into the
buffer remaining in the seq_buf structure. The return of vsnprintf()
is the amount of characters written to the buffer excluding the '\0',
unless the line was truncated!

If the line copied does not fit, it is truncated, and a '\0' is added
to the end of the buffer. But in this case, '\0' is included in the length
of the line written. To know if the buffer had overflowed, the return
length will be the same as the length of the buffer passed in.

The check in seq_buf_vprintf() only checked if the length returned from
vsnprintf() would fit in the buffer, as the seq_buf_vprintf() is only
to be an all or nothing command. It either writes all the string into
the seq_buf, or none of it. If the string is truncated, the pointers
inside the seq_buf must be reset to what they were when the function was
called. This is not the case. On overflow, it copies only part of the string.

The fix is to change the overflow check to see if the length returned from
vsnprintf() is less than the length remaining in the seq_buf buffer, and not
if it is less than or equal to as it currently does. Then seq_buf_vprintf()
will know if the write from vsnpritnf() was truncated or not.

Cc: stable@vger.kernel.org
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 lib/seq_buf.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/seq_buf.c b/lib/seq_buf.c
index 88c0854bd752..0c92583b7b7e 100644
--- a/lib/seq_buf.c
+++ b/lib/seq_buf.c
@@ -61,7 +61,7 @@ int seq_buf_vprintf(struct seq_buf *s, const char *fmt, va_list args)
 
 	if (s->len < s->size) {
 		len = vsnprintf(s->buffer + s->len, s->size - s->len, fmt, args);
-		if (seq_buf_can_fit(s, len)) {
+		if (s->len + len < s->size) {
 			s->len += len;
 			return 0;
 		}
-- 
2.1.4

[PATCH 2/5] seq_buf: Fix seq_buf_bprintf() truncation

[Steven Rostedt]

[-- Attachment #1: 0002-seq_buf-Fix-seq_buf_bprintf-truncation.patch --]
[-- Type: text/plain, Size: 2011 bytes --]

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

In seq_buf_bprintf(), bstr_printf() is used to copy the format into the
buffer remaining in the seq_buf structure. The return of bstr_printf()
is the amount of characters written to the buffer excluding the '\0',
unless the line was truncated!

If the line copied does not fit, it is truncated, and a '\0' is added
to the end of the buffer. But in this case, '\0' is included in the length
of the line written. To know if the buffer had overflowed, the return
length will be the same or greater than the length of the buffer passed in.

The check in seq_buf_bprintf() only checked if the length returned from
bstr_printf() would fit in the buffer, as the seq_buf_bprintf() is only
to be an all or nothing command. It either writes all the string into
the seq_buf, or none of it. If the string is truncated, the pointers
inside the seq_buf must be reset to what they were when the function was
called. This is not the case. On overflow, it copies only part of the string.

The fix is to change the overflow check to see if the length returned from
bstr_printf() is less than the length remaining in the seq_buf buffer, and not
if it is less than or equal to as it currently does. Then seq_buf_bprintf()
will know if the write from bstr_printf() was truncated or not.

Link: http://lkml.kernel.org/r/1425500481.2712.27.camel@perches.com

Cc: stable@vger.kernel.org
Reported-by: Joe Perches <joe@perches.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 lib/seq_buf.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/seq_buf.c b/lib/seq_buf.c
index 0c92583b7b7e..5c94e1012a91 100644
--- a/lib/seq_buf.c
+++ b/lib/seq_buf.c
@@ -118,7 +118,7 @@ int seq_buf_bprintf(struct seq_buf *s, const char *fmt, const u32 *binary)
 
 	if (s->len < s->size) {
 		ret = bstr_printf(s->buffer + s->len, len, fmt, binary);
-		if (seq_buf_can_fit(s, ret)) {
+		if (s->len + ret < s->size) {
 			s->len += ret;
 			return 0;
 		}
-- 
2.1.4

[PATCH 3/5] ftrace: Clear REGS_EN and TRAMP_EN flags on disabling record via sysctl

[Steven Rostedt]

[-- Attachment #1: 0003-ftrace-Clear-REGS_EN-and-TRAMP_EN-flags-on-disabling.patch --]
[-- Type: text/plain, Size: 2414 bytes --]

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

When /proc/sys/kernel/ftrace_enabled is set to zero, all function
tracing is disabled. But the records that represent the functions
still hold information about the ftrace_ops that are hooked to them.

ftrace_ops may request "REGS" (have a full set of pt_regs passed to
the callback), or "TRAMP" (the ops has its own trampoline to use).
When the record is updated to represent the state of the ops hooked
to it, it sets "REGS_EN" and/or "TRAMP_EN" to state that the callback
points to the correct trampoline (REGS has its own trampoline).

When ftrace_enabled is set to zero, all ftrace locations are a nop,
so they do not point to any trampoline. But the _EN flags are still
set. This can cause the accounting to go wrong when ftrace_enabled
is cleared and an ops that has a trampoline is registered or unregistered.

For example, the following will cause ftrace to crash:

 # echo function_graph > /sys/kernel/debug/tracing/current_tracer
 # echo 0 > /proc/sys/kernel/ftrace_enabled
 # echo nop > /sys/kernel/debug/tracing/current_tracer
 # echo 1 > /proc/sys/kernel/ftrace_enabled
 # echo function_graph > /sys/kernel/debug/tracing/current_tracer

As function_graph uses a trampoline, when ftrace_enabled is set to zero
the updates to the record are not done. When enabling function_graph
again, the record will still have the TRAMP_EN flag set, and it will
look for an op that has a trampoline other than the function_graph
ops, and fail to find one.

Cc: stable@vger.kernel.org # 3.17+
Reported-by: Pratyush Anand <panand@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ftrace.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 45e5cb143d17..14947e014b78 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2041,8 +2041,12 @@ static int ftrace_check_record(struct dyn_ftrace *rec, int enable, int update)
 		if (!ftrace_rec_count(rec))
 			rec->flags = 0;
 		else
-			/* Just disable the record (keep REGS state) */
-			rec->flags &= ~FTRACE_FL_ENABLED;
+			/*
+			 * Just disable the record, but keep the ops TRAMP
+			 * and REGS states. The _EN flags must be disabled though.
+			 */
+			rec->flags &= ~(FTRACE_FL_ENABLED | FTRACE_FL_TRAMP_EN |
+					FTRACE_FL_REGS_EN);
 	}
 
 	return FTRACE_UPDATE_MAKE_NOP;
-- 
2.1.4

[PATCH 4/5] ftrace: Fix en(dis)able graph caller when en(dis)abling record via sysctl

[Steven Rostedt]

[-- Attachment #1: 0004-ftrace-Fix-en-dis-able-graph-caller-when-en-dis-abli.patch --]
[-- Type: text/plain, Size: 4226 bytes --]

From: Pratyush Anand <panand@redhat.com>

When ftrace is enabled globally through the proc interface, we must check if
ftrace_graph_active is set. If it is set, then we should also pass the
FTRACE_START_FUNC_RET command to ftrace_run_update_code(). Similarly, when
ftrace is disabled globally through the proc interface, we must check if
ftrace_graph_active is set. If it is set, then we should also pass the
FTRACE_STOP_FUNC_RET command to ftrace_run_update_code().

Consider the following situation.

 # echo 0 > /proc/sys/kernel/ftrace_enabled

After this ftrace_enabled = 0.

 # echo function_graph > /sys/kernel/debug/tracing/current_tracer

Since ftrace_enabled = 0, ftrace_enable_ftrace_graph_caller() is never
called.

 # echo 1 > /proc/sys/kernel/ftrace_enabled

Now ftrace_enabled will be set to true, but still
ftrace_enable_ftrace_graph_caller() will not be called, which is not
desired.

Further if we execute the following after this:
  # echo nop > /sys/kernel/debug/tracing/current_tracer

Now since ftrace_enabled is set it will call
ftrace_disable_ftrace_graph_caller(), which causes a kernel warning on
the ARM platform.

On the ARM platform, when ftrace_enable_ftrace_graph_caller() is called,
it checks whether the old instruction is a nop or not. If it's not a nop,
then it returns an error. If it is a nop then it replaces instruction at
that address with a branch to ftrace_graph_caller.
ftrace_disable_ftrace_graph_caller() behaves just the opposite. Therefore,
if generic ftrace code ever calls either ftrace_enable_ftrace_graph_caller()
or ftrace_disable_ftrace_graph_caller() consecutively two times in a row,
then it will return an error, which will cause the generic ftrace code to
raise a warning.

Note, x86 does not have an issue with this because the architecture
specific code for ftrace_enable_ftrace_graph_caller() and
ftrace_disable_ftrace_graph_caller() does not check the previous state,
and calling either of these functions twice in a row has no ill effect.

Link: http://lkml.kernel.org/r/e4fbe64cdac0dd0e86a3bf914b0f83c0b419f146.1425666454.git.panand@redhat.com

Cc: stable@vger.kernel.org # 2.6.31+
Signed-off-by: Pratyush Anand <panand@redhat.com>
[
  removed extra if (ftrace_start_up) and defined ftrace_graph_active as 0
  if CONFIG_FUNCTION_GRAPH_TRACER is not set.
]
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ftrace.c | 28 ++++++++++++++++++++++------
 1 file changed, 22 insertions(+), 6 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 14947e014b78..ea520bb54d44 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -1059,6 +1059,12 @@ static __init void ftrace_profile_debugfs(struct dentry *d_tracer)
 
 static struct pid * const ftrace_swapper_pid = &init_struct_pid;
 
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+static int ftrace_graph_active;
+#else
+# define ftrace_graph_active 0
+#endif
+
 #ifdef CONFIG_DYNAMIC_FTRACE
 
 static struct ftrace_ops *removed_ops;
@@ -2692,24 +2698,36 @@ static int ftrace_shutdown(struct ftrace_ops *ops, int command)
 
 static void ftrace_startup_sysctl(void)
 {
+	int command;
+
 	if (unlikely(ftrace_disabled))
 		return;
 
 	/* Force update next time */
 	saved_ftrace_func = NULL;
 	/* ftrace_start_up is true if we want ftrace running */
-	if (ftrace_start_up)
-		ftrace_run_update_code(FTRACE_UPDATE_CALLS);
+	if (ftrace_start_up) {
+		command = FTRACE_UPDATE_CALLS;
+		if (ftrace_graph_active)
+			command |= FTRACE_START_FUNC_RET;
+		ftrace_run_update_code(command);
+	}
 }
 
 static void ftrace_shutdown_sysctl(void)
 {
+	int command;
+
 	if (unlikely(ftrace_disabled))
 		return;
 
 	/* ftrace_start_up is true if ftrace is running */
-	if (ftrace_start_up)
-		ftrace_run_update_code(FTRACE_DISABLE_CALLS);
+	if (ftrace_start_up) {
+		command = FTRACE_DISABLE_CALLS;
+		if (ftrace_graph_active)
+			command |= FTRACE_STOP_FUNC_RET;
+		ftrace_run_update_code(command);
+	}
 }
 
 static cycle_t		ftrace_update_time;
@@ -5594,8 +5612,6 @@ static struct ftrace_ops graph_ops = {
 	ASSIGN_OPS_HASH(graph_ops, &global_ops.local_hash)
 };
 
-static int ftrace_graph_active;
-
 int ftrace_graph_entry_stub(struct ftrace_graph_ent *trace)
 {
 	return 0;
-- 
2.1.4

[PATCH 5/5] ftrace: Fix ftrace enable ordering of sysctl ftrace_enabled

[Steven Rostedt]

[-- Attachment #1: 0005-ftrace-Fix-ftrace-enable-ordering-of-sysctl-ftrace_e.patch --]
[-- Type: text/plain, Size: 2099 bytes --]

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

Some archs (specifically PowerPC), are sensitive with the ordering of
the enabling of the calls to function tracing and setting of the
function to use to be traced.

That is, update_ftrace_function() sets what function the ftrace_caller
trampoline should call. Some archs require this to be set before
calling ftrace_run_update_code().

Another bug was discovered, that ftrace_startup_sysctl() called
ftrace_run_update_code() directly. If the function the ftrace_caller
trampoline changes, then it will not be updated. Instead a call
to ftrace_startup_enable() should be called because it tests to see
if the callback changed since the code was disabled, and will
tell the arch to update appropriately. Most archs do not need this
notification, but PowerPC does.

The problem could be seen by the following commands:

 # echo 0 > /proc/sys/kernel/ftrace_enabled
 # echo function > /sys/kernel/debug/tracing/current_tracer
 # echo 1 > /proc/sys/kernel/ftrace_enabled
 # cat /sys/kernel/debug/tracing/trace

The trace will show that function tracing was not active.

Cc: stable@vger.kernel.org # 2.6.27+
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/ftrace.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index ea520bb54d44..4f228024055b 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2710,7 +2710,7 @@ static void ftrace_startup_sysctl(void)
 		command = FTRACE_UPDATE_CALLS;
 		if (ftrace_graph_active)
 			command |= FTRACE_START_FUNC_RET;
-		ftrace_run_update_code(command);
+		ftrace_startup_enable(command);
 	}
 }
 
@@ -5580,12 +5580,12 @@ ftrace_enable_sysctl(struct ctl_table *table, int write,
 
 	if (ftrace_enabled) {
 
-		ftrace_startup_sysctl();
-
 		/* we are starting ftrace again */
 		if (ftrace_ops_list != &ftrace_list_end)
 			update_ftrace_function();
 
+		ftrace_startup_sysctl();
+
 	} else {
 		/* stopping ftrace calls (just send to ftrace_stub) */
 		ftrace_trace_function = ftrace_stub;
-- 
2.1.4

Re: [PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[Linus Torvalds]

On Mon, Mar 9, 2015 at 9:03 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
>
> This is on top of the last pull request I sent out. But doesn't seem to
> have been pulled.

You make no sense. The commits you list were all on top of plain 4.0-rc2.

So exactly what do you expect me to pull, or haven't I pulled?

                      Linus

Re: [PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[Steven Rostedt]

On Mon, 9 Mar 2015 18:14:26 -0700
Linus Torvalds <torvalds@linux-foundation.org> wrote:

> On Mon, Mar 9, 2015 at 9:03 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > This is on top of the last pull request I sent out. But doesn't seem to
> > have been pulled.
> 
> You make no sense. The commits you list were all on top of plain 4.0-rc2.
> 
> So exactly what do you expect me to pull, or haven't I pulled?

The confusing part is that I included the patch in this series that I
had in my previous pull request that you did not pull...

 http://marc.info/?l=linux-kernel&m=142549997928187

-- Steve

Re: [PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[Linus Torvalds]

On Mon, Mar 9, 2015 at 6:36 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
>
> The confusing part is that I included the patch in this series that I
> had in my previous pull request that you did not pull...

Oh. Ok. I didn't pull that, simply because in the same thread you said
you were going to fix the other case that Joe pointed out and you said
"I'll make another patch". So I dismissed your previous pull request
as premature..

                      Linus

Re: [PATCH 0/5] [GIT PULL] seq-buf/ftrace: Various fixes

[Steven Rostedt]

On Mon, 9 Mar 2015 18:43:54 -0700
Linus Torvalds <torvalds@linux-foundation.org> wrote:


> Oh. Ok. I didn't pull that, simply because in the same thread you said
> you were going to fix the other case that Joe pointed out and you said
> "I'll make another patch". So I dismissed your previous pull request
> as premature..

Yeah I figured as much. But right after I did that fix, the other bug
was reported to me. I decided to fix that bug before posting again, and
that took a bit longer than I expected.

Sorry for the confusion, I didn't explain it very well. I should have
stated this is the new update to my previous pull request with another
bug fix included as well.

-- Steve