linux-kernel - Re: Q: perf log mode?

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:	Wed, 12 Jan 2011 13:21:12 -0200
From:	Arnaldo Carvalho de Melo <acme@...radead.org>
To:	Kirill Smelkov <kirr@....spb.ru>
Cc:	linux-kernel@...r.kernel.org,
	Frederic Weisbecker <fweisbec@...il.com>,
	Ingo Molnar <mingo@...e.hu>, Mike Galbraith <efault@....de>,
	Paul Mackerras <paulus@...ba.org>,
	Peter Zijlstra <peterz@...radead.org>,
	Stephane Eranian <eranian@...gle.com>,
	Tom Zanussi <tzanussi@...il.com>
Subject: Re: Q: perf log mode?

Em Wed, Jan 12, 2011 at 05:06:13PM +0300, Kirill Smelkov escreveu:
> I'm trying to use perf together with e.g. kprobes as a tool to show what
> is happening with my system in "live-log" mode. The problem is, for
> seldom events, actual info output is largely delayed because perf reads
> sample data in whole pages. Could something be done with it or am I'm
> missing something? Here is detailed description:

<SNIP>
> 
> Judging from timestamps, the events were coming with 1-2 seconds period
> (ping <host> running) and for e.g. first event we got 96-43=53 seconds
> delay (which is happening already at `perf record` stage -- I've
> monitored it's raw output).
> 
> Is it somehow possible to display events instantly as they are coming?

Look at how perf top works:

        while (1) {
                int hits = samples;

                perf_session__mmap_read(session);

                if (hits == samples)
                        ret = poll(evsel_list->pollfd, evsel_list->nr_fds, 100);
        }

It will only call poll if no events were found so there should be no
delays.

perf script instead uses perf_session__process_events() and that, as
requested by 'perf script' queues events to make sure they are ordered,
so probably the problem is related to this latency, probably we'll need
to use some timer to flush this queue more often.

Try tweaking:

        .ordering_requires_timestamps = true,
        .ordered_samples = true,

in builtin-script.c, if you disable those there should be no queueing
and we'll test this theory.

Also try checking if there isn't any buffering in action because it uses
pipes to connect the record with the python script by printing the event
as it comes in the record part.

- Arnaldo
--
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/