Re: Perf trace event parse errors for KVM events

[Steven Rostedt]

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@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@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@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/