2013-08-02 17:17:07

by Andrei Vagin

[permalink] [raw]
Subject: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake

tracing_read_pipe zeros all fields bellow "seq". The declaration contains
a comment about that, but it doesn't help.

The first field is "snapshot", it's true when current open file is
snapshot. Looks obvious, that it should not be zeroed.

The second field is "started". It was converted from cpumask_t to
cpumask_var_t (v2.6.28-4983-g4462344) or by another words it was
converted from cpumask to pointer on cpumask.

Currently the reference on "started" memory is lost after the first read
from tracing_read_pipe and a proper object will never be freed.

The "started" is never dereferenced for trace_pipe, because trace_pipe
can't have the TRACE_FILE_ANNOTATE options (why?).

Cc: Steven Rostedt <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: David Sharp <[email protected]>
Cc: Hiraku Toyooka <[email protected]>
Cc: Arjan van de Ven <[email protected]>
Cc: Masami Hiramatsu <[email protected]>

Signed-off-by: Andrew Vagin <[email protected]>
---
include/linux/ftrace_event.h | 10 ++++++----
kernel/trace/trace.c | 1 +
2 files changed, 7 insertions(+), 4 deletions(-)

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 4372658..44cdc11 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -78,6 +78,11 @@ struct trace_iterator {
/* trace_seq for __print_flags() and __print_symbolic() etc. */
struct trace_seq tmp_seq;

+ cpumask_var_t started;
+
+ /* it's true when current open file is snapshot */
+ bool snapshot;
+
/* The below is zeroed out in pipe_read */
struct trace_seq seq;
struct trace_entry *ent;
@@ -90,10 +95,7 @@ struct trace_iterator {
loff_t pos;
long idx;

- cpumask_var_t started;
-
- /* it's true when current open file is snapshot */
- bool snapshot;
+ /* All new field here will be zeroed out in pipe_read */
};

enum trace_iter_flags {
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0cd500b..897f553 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4166,6 +4166,7 @@ waitagain:
memset(&iter->seq, 0,
sizeof(struct trace_iterator) -
offsetof(struct trace_iterator, seq));
+ cpumask_clear(iter->started);
iter->pos = -1;

trace_event_read_lock();
--
1.7.1


2013-08-02 18:15:58

by David Sharp

[permalink] [raw]
Subject: Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake

On Fri, Aug 2, 2013 at 10:16 AM, Andrew Vagin <[email protected]> wrote:
> tracing_read_pipe zeros all fields bellow "seq". The declaration contains
> a comment about that, but it doesn't help.
>
> The first field is "snapshot", it's true when current open file is
> snapshot. Looks obvious, that it should not be zeroed.
>
> The second field is "started". It was converted from cpumask_t to
> cpumask_var_t (v2.6.28-4983-g4462344) or by another words it was
> converted from cpumask to pointer on cpumask.
>
> Currently the reference on "started" memory is lost after the first read
> from tracing_read_pipe and a proper object will never be freed.
>
> The "started" is never dereferenced for trace_pipe, because trace_pipe
> can't have the TRACE_FILE_ANNOTATE options (why?).
>
> Cc: Steven Rostedt <[email protected]>
> Cc: Frederic Weisbecker <[email protected]>
> Cc: Ingo Molnar <[email protected]>
> Cc: David Sharp <[email protected]>
> Cc: Hiraku Toyooka <[email protected]>
> Cc: Arjan van de Ven <[email protected]>
> Cc: Masami Hiramatsu <[email protected]>
>
> Signed-off-by: Andrew Vagin <[email protected]>
> ---
> include/linux/ftrace_event.h | 10 ++++++----
> kernel/trace/trace.c | 1 +
> 2 files changed, 7 insertions(+), 4 deletions(-)
>
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index 4372658..44cdc11 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -78,6 +78,11 @@ struct trace_iterator {
> /* trace_seq for __print_flags() and __print_symbolic() etc. */
> struct trace_seq tmp_seq;
>
> + cpumask_var_t started;
> +
> + /* it's true when current open file is snapshot */
> + bool snapshot;
> +
> /* The below is zeroed out in pipe_read */
> struct trace_seq seq;
> struct trace_entry *ent;
> @@ -90,10 +95,7 @@ struct trace_iterator {
> loff_t pos;
> long idx;
>
> - cpumask_var_t started;
> -
> - /* it's true when current open file is snapshot */
> - bool snapshot;
> + /* All new field here will be zeroed out in pipe_read */

Wow. That is a terrible hack. Thanks for noticing it.

If I may suggest a way better idea: put these zeroed-in-pipe_read
members in an embedded anonymous structure, and zero the structure in
pipe_read.

> };
>
> enum trace_iter_flags {
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 0cd500b..897f553 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4166,6 +4166,7 @@ waitagain:
> memset(&iter->seq, 0,
> sizeof(struct trace_iterator) -
> offsetof(struct trace_iterator, seq));
> + cpumask_clear(iter->started);
> iter->pos = -1;
>
> trace_event_read_lock();
> --
> 1.7.1
>

2013-08-02 18:32:37

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake

On Fri, 2013-08-02 at 11:15 -0700, David Sharp wrote:

> Wow. That is a terrible hack. Thanks for noticing it.

Why thank you :-)

It's a hack from doing things that way else where and long ago.

>
> If I may suggest a way better idea: put these zeroed-in-pipe_read
> members in an embedded anonymous structure, and zero the structure in
> pipe_read.

Sure, sounds like a fix for 3.12.

-- Steve

2013-08-03 01:21:28

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake

On Fri, 2013-08-02 at 21:16 +0400, Andrew Vagin wrote:
> tracing_read_pipe zeros all fields bellow "seq". The declaration contains
> a comment about that, but it doesn't help.
>
> The first field is "snapshot", it's true when current open file is
> snapshot. Looks obvious, that it should not be zeroed.
>
> The second field is "started". It was converted from cpumask_t to
> cpumask_var_t (v2.6.28-4983-g4462344) or by another words it was
> converted from cpumask to pointer on cpumask.
>
> Currently the reference on "started" memory is lost after the first read
> from tracing_read_pipe and a proper object will never be freed.

This should be marked for stable, namely for the started mask being
leaked.

>
> The "started" is never dereferenced for trace_pipe, because trace_pipe
> can't have the TRACE_FILE_ANNOTATE options (why?).

I guess it could, but it's not necessary because trace_pipe has the lost
event counter which basically does the same thing. The annotate was to
please people like Thomas Gleixner, that was confused by the trace file
output where it looked like a bunch happened on CPU 1 and nothing on any
of the other CPUs. But in reality, it was that CPU 1 didn't have many
events and all the other CPUs overwrote their buffers more recently.

The consuming nature of trace_pipe, I left out most of the annotations,
like the header and these annotations. trace_pipe was mainly used to see
events live, no annotation necessary, except for lost events. The lost
events do take over for this instead. As the trace file is more of a
"snapshot" in time (tracing stops when reading that file but not the
trace_pipe file) it shouldn't have lost events. It should see the trace
as complete. Although, due to the reader page nature, there can be a gap
between the reader page and the main buffer.


>
> Cc: Steven Rostedt <[email protected]>
> Cc: Frederic Weisbecker <[email protected]>
> Cc: Ingo Molnar <[email protected]>
> Cc: David Sharp <[email protected]>
> Cc: Hiraku Toyooka <[email protected]>
> Cc: Arjan van de Ven <[email protected]>
> Cc: Masami Hiramatsu <[email protected]>
>
> Signed-off-by: Andrew Vagin <[email protected]>
> ---
> include/linux/ftrace_event.h | 10 ++++++----
> kernel/trace/trace.c | 1 +
> 2 files changed, 7 insertions(+), 4 deletions(-)
>
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index 4372658..44cdc11 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -78,6 +78,11 @@ struct trace_iterator {
> /* trace_seq for __print_flags() and __print_symbolic() etc. */
> struct trace_seq tmp_seq;
>
> + cpumask_var_t started;
> +
> + /* it's true when current open file is snapshot */
> + bool snapshot;
> +

The above two should be swapped. snapshot doesn't change in trace pipe,
but started does.

> /* The below is zeroed out in pipe_read */
> struct trace_seq seq;
> struct trace_entry *ent;
> @@ -90,10 +95,7 @@ struct trace_iterator {
> loff_t pos;
> long idx;
>
> - cpumask_var_t started;
> -
> - /* it's true when current open file is snapshot */
> - bool snapshot;
> + /* All new field here will be zeroed out in pipe_read */
> };
>
> enum trace_iter_flags {
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 0cd500b..897f553 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4166,6 +4166,7 @@ waitagain:
> memset(&iter->seq, 0,
> sizeof(struct trace_iterator) -
> offsetof(struct trace_iterator, seq));
> + cpumask_clear(iter->started);

Hmm, on second thought should it change? it's ignored because we never
set the TRACE_FILE_ANNOTATE flag in the iterator.

That means that we don't even need the setall in tracing_open_pipe.
Technically, would shouldn't even allocate it, but for now we should,
just to be safe.

-- Steve



> iter->pos = -1;
>
> trace_event_read_lock();

2013-08-03 01:55:25

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake

On Fri, 2013-08-02 at 21:21 -0400, Steven Rostedt wrote:

> That means that we don't even need the setall in tracing_open_pipe.
> Technically, would shouldn't even allocate it, but for now we should,
> just to be safe.

Your patch is fine as it is. I'll do the other cleanups for 3.12.
Thanks!

-- Steve