linux-kernel - Re: Perf trace event parse errors for KVM events

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Thu, 03 Jun 2010 17:57:05 -0400
From:	Steven Rostedt <rostedt@...dmis.org>
To:	Avi Kivity <avi@...hat.com>
Cc:	Stefan Hajnoczi <stefanha@...il.com>,
	linux-perf-users@...r.kernel.org, linux-kernel@...r.kernel.org,
	kvm@...r.kernel.org, Frederic Weisbecker <fweisbec@...il.com>,
	Marcelo Tosatti <mtosatti@...hat.com>,
	Peter Zijlstra <a.p.zijlstra@...llo.nl>,
	Stefan Hajnoczi <stefanha@...ux.vnet.ibm.com>,
	Johannes Berg <johannes.berg@...el.com>,
	Darren Hart <darren@...art.com>
Subject: Re: Perf trace event parse errors for KVM events

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