[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20091021073442.GA2343@jolsa.lab.eng.brq.redhat.com>
Date: Wed, 21 Oct 2009 09:34:43 +0200
From: Jiri Olsa <jolsa@...hat.com>
To: Frederic Weisbecker <fweisbec@...il.com>
Cc: mingo@...e.hu, rostedt@...dmis.org, linux-kernel@...r.kernel.org
Subject: Re: [PATCH] tracing - fix function graph trace to properly skip
records
On Tue, Oct 20, 2009 at 07:11:54PM +0200, Frederic Weisbecker wrote:
> On Tue, Oct 20, 2009 at 06:00:39PM +0200, Jiri Olsa wrote:
> > Hi,
> >
> > there's a case where the graph tracer might get confused and displays
> > "{}" brackets in a wrong way.
> >
> > Sorry for long description, but I found no better way to
> > describe the issue.. ;)
> >
>
>
> I rather consider this changelog as nicely decribing the issue.
>
>
> > It works ok but for one case.
> >
> > If the "func2()" trace does not make it to the seq_file read buffer, it needs
> > to be processed again in the next read. And here comes the issue:
> > the next read will see following pointers setup for func2 processing:
> >
> > func1 ENTRY
> > current -> func2 ENTRY
> > func2 RETURN
> > next -> func1 RETURN
> >
> > which will turn to displaying the func2 entry like: "func2() {", since the
> > next entry is not RETURN of the same type. Generaly it is whatever entry
> > that follows, but definitelly not the RETURN entry of the same function.
>
>
>
> I see... So that happens when the previous seq write failed, we already have
> consume func2 RETURN and because we returned TRACE_PARTIAL_LINE, we reprocess
> func2 ENTRY, but the next entry pointer have moved ahead already...
>
> Nice catch!
>
>
> > Following patch fixes the issue by skipping the entry in the last moment,
> > bypassing the issue to happen during the sequential reads.
> >
> > wbr,
> > jirka
> >
> >
> > NOTE:
> >
> > AFAIK patch does not affect "trace_pipe" handling, since the change is
> > on the ring_buffer_iter level. However the "trace_pipe" suffers from
> > the same issue -> when the read buffer is filled up, the current trace
> > entry is not copied to it. Following read will continue with next entry.
> > It might be harder to fix this, since "trace_pipe" in order to see next
> > record has to eat the current one...
> >
> > I'll look at possible solution, but any ideas are welcome.. :)
> >
> >
> >
> > Signed-off-by: Jiri Olsa <jolsa@...hat.com>
> > ---
> > include/linux/ftrace_event.h | 1 +
> > kernel/trace/trace.c | 29 +++++++++++++++++++++++++++++
> > kernel/trace/trace_functions_graph.c | 2 +-
> > 3 files changed, 31 insertions(+), 1 deletions(-)
> >
> > diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> > index d117704..7b07ad2 100644
> > --- a/include/linux/ftrace_event.h
> > +++ b/include/linux/ftrace_event.h
> > @@ -53,6 +53,7 @@ struct trace_iterator {
> > struct mutex mutex;
> > struct ring_buffer_iter *buffer_iter[NR_CPUS];
> > unsigned long iter_flags;
> > + bool skip_entry;
>
>
> Instead of adding this new field to struct trace_iterator,
> why not creating a new return value like TRACE_TYPE_HANDLED
> but that would consume two entries instead of one?
>
> May be TRACE_TYPE_HANDLED_2? (sorry I suck in naming).
>
> TRACE_TYPE_HANDLED_PAIR?
> TRACE_TYPE_HANDLED_COUPLE?
>
I think we need to hold the state of crossing 2 entries, since the
issue happens when the seq_write fails, so there will be next read
operation, which needs to know what to do.
jirka
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists