From: Steven Rostedt on
On Sun, 2010-05-30 at 17:07 +0300, Avi Kivity wrote:
> On 05/30/2010 05:03 PM, Steven Rostedt wrote:
> >
> >> Right. The tools can fall back to %x/%s based on the structure
> >> descriptor if they can't parse the format string.
> >>
> >>
> > trace-cmd has plugin support to override how to read the format and
> > print it out. It now has the ability to write those plugins in python.
> >
>
> Cool. May make sense to use simpler formatting in the kernel, and use
> trace-cmd plugins for the complicated cases.
>
> It does raise issues with ABIs. Can trace-cmd read plugins from
> /lib/modules/*? We can then distribute the plugins with the kernel.
>

We probably could do that. Perhaps if we can port the python code to
perf, then it would work for both. Then the plugins could be just python
scripts, (or binary .so modules) and have a tools/plugins dir?

The python part probably would be easier to port, since the .so modules
are a bit more specific to trace-cmd.

-- Steve


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Avi Kivity on
On 05/30/2010 06:34 PM, Steven Rostedt wrote:
>
>> Cool. May make sense to use simpler formatting in the kernel, and use
>> trace-cmd plugins for the complicated cases.
>>
>> It does raise issues with ABIs. Can trace-cmd read plugins from
>> /lib/modules/*? We can then distribute the plugins with the kernel.
>>
>>
> We probably could do that. Perhaps if we can port the python code to
> perf, then it would work for both. Then the plugins could be just python
> scripts, (or binary .so modules) and have a tools/plugins dir?
>
> The python part probably would be easier to port, since the .so modules
> are a bit more specific to trace-cmd.
>

One concern is performance. Traces tend to be long, and running python
code on each line will be slow.

If trace-cmd integrates a pager and a search mechanism that looks at the
binary data instead of the text, we could format only the lines that are
displayed. But that is going to be a lot of work and I don't think it's
worth the effort.

--
error compiling committee.c: too many arguments to function

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Steven Rostedt on
On Tue, 2010-06-01 at 11:39 +0300, Avi Kivity wrote:
> On 05/30/2010 06:34 PM, Steven Rostedt wrote:
> >
> >> Cool. May make sense to use simpler formatting in the kernel, and use
> >> trace-cmd plugins for the complicated cases.
> >>
> >> It does raise issues with ABIs. Can trace-cmd read plugins from
> >> /lib/modules/*? We can then distribute the plugins with the kernel.
> >>
> >>
> > We probably could do that. Perhaps if we can port the python code to
> > perf, then it would work for both. Then the plugins could be just python
> > scripts, (or binary .so modules) and have a tools/plugins dir?
> >
> > The python part probably would be easier to port, since the .so modules
> > are a bit more specific to trace-cmd.
> >
>
> One concern is performance. Traces tend to be long, and running python
> code on each line will be slow.
>
> If trace-cmd integrates a pager and a search mechanism that looks at the
> binary data instead of the text, we could format only the lines that are
> displayed. But that is going to be a lot of work and I don't think it's
> worth the effort.
>

Every event gets its own ID. The plugin registers a callback to that ID.
When the ID is hit, the plugin is executed on that event to display its
binary format.

This is done after the data has been saved in binary format to a file.
It may slow down the executing of reading a data file, but it does not
affect the running of the trace one bit.

-- Steve


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Avi Kivity on
On 06/01/2010 02:59 PM, Steven Rostedt wrote:
>
>> One concern is performance. Traces tend to be long, and running python
>> code on each line will be slow.
>>
>> If trace-cmd integrates a pager and a search mechanism that looks at the
>> binary data instead of the text, we could format only the lines that are
>> displayed. But that is going to be a lot of work and I don't think it's
>> worth the effort.
>>
>>
> Every event gets its own ID. The plugin registers a callback to that ID.
> When the ID is hit, the plugin is executed on that event to display its
> binary format.
>
> This is done after the data has been saved in binary format to a file.
> It may slow down the executing of reading a data file, but it does not
> affect the running of the trace one bit.
>

I meant that viewing would be slowed down. It's an important part of
using ftrace!

How long does the Python formatter take to process 100k or 1M events?

--
error compiling committee.c: too many arguments to function

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Steven Rostedt on
On Tue, 2010-06-01 at 15:39 +0300, Avi Kivity wrote:
> On 06/01/2010 02:59 PM, Steven Rostedt wrote:

> I meant that viewing would be slowed down. It's an important part of
> using ftrace!
>
> How long does the Python formatter take to process 100k or 1M events?
>

I finally got around to testing this.

I ran a trace on lock_acquire, and traced 1,253,296 events.

I then created a python plugin to analyze the trace:

----
def lock_acquire(trace_seq, event):
t = ''
r = ''
if int(event['flags']) & 1:
t = 'try'
if int(event['flags']) & 2:
r = 'read'
trace_seq.puts('t %x %s%s%s' % (
event['lockdep_addr'], t, r,
event['name']))

def register(pevent):
pevent.register_event_handler("lock", "lock_acquire", lock_acquire)
----

Disclaimer, I'm not a python expert, and I'm sure the above python code
sucks.


[root(a)ixf9 trace-cmd.git]# time ./trace-cmd report -N >/dev/null 2>&1

real 0m4.653s
user 0m4.234s
sys 0m0.419s

* -N keeps trace-cmd from loading any plugins.


[root(a)ixf9 trace-cmd.git]# time PYTHONPATH=`pwd` ./trace-cmd report >/dev/null 2>&1

real 0m53.916s
user 0m53.047s
sys 0m0.859s


Yes, running a python interpreter is a bit more expensive. It took 4
seconds to read the million events with plain C, but 53 seconds to read
it in python.

That said... This would only affect you if you were writing this to a
file. I doubt that you would notice this if you were scanning the trace
with less.

Also, I kicked this off in kernelshark, and it made no difference that I
can see. This is because kernelshark only evaluates the viewable area of
the screen.

-- Steve





--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/