Re: [RFC/PATCH] perf stat: Show sample events stat for a data file

From: Namhyung Kim
Date: Wed Apr 29 2015 - 07:59:38 EST


Hi Peter,

On Wed, Apr 29, 2015 at 11:27:51AM +0200, Peter Zijlstra wrote:
> On Wed, Apr 29, 2015 at 04:27:45PM +0900, Namhyung Kim wrote:
> > Add --input option to 'perf stat' so that it can show event stats of the
> > file. I would like to use a short '-i' option to be compatible with
> > other commands but it was already taken by '--no-inherit' option, so it
> > only supports the long option.
> >
> > The example output looks like below:
> >
> > $ perf record -a sleep 1
> > [ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.635 MB perf.data (1946 samples) ]
> >
> > $ perf stat --input perf.data
> >
> > Total event stats for 'perf.data' file:
> >
> > TOTAL events: 6837
> > MMAP events: 116
> > COMM events: 375
> > EXIT events: 2
> > THROTTLE events: 12
> > UNTHROTTLE events: 11
> > FORK events: 374
> > SAMPLE events: 1946
> > MMAP2 events: 3999
> > FINISHED_ROUND events: 2
> >
> > Sample event stats:
> >
> > 361,255,234 cycles
> > 1,946 samples # sampling ratio 12.162% (486/4000)
> >
> > 0.998581085 second time sampled
>
> It would be nice if this thing could support 'perf record -s' which
> enables perf_event_attr::inherit_stat, which in turn results in
> PERF_RECORD_READ entries after every PERF_RECORD_EXIT which give the
> total number of events for each recorded task.

Hmm.. this is one of the areas that I don't understand what's going
on. It'd be nice if you can help me understand and possibly improve
the doc too.

So the combination of 'perf record -s' and 'perf report -T' should
show some per-thread counter values, right? I've found a bug on it.

Anyway, I don't understand the numbers it shows.

$ perf record -s -- perf bench sched messaging
# Running 'sched/messaging' benchmark:
# 20 sender and receiver processes per group
# 10 groups == 400 processes run

Total time: 0.192 [sec]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.376 MB perf.data (6806 samples) ]


$ perf report -T --stdio
...
# PID TID cycles cycles cycles cycles cycles
9728 9728 5865527 0 0 0 0
9686 9686 0 0 5692534 0 0
9650 9650 0 0 0 0 0
9649 9649 5578209 0 0 0 0
9685 9685 6227490 0 0 0 0
9596 9596 0 140483569056856 0 0 0
9837 9837 120079 140483569056856 0 0 0
9561 9561 0 140483569056856 0 0 0
9475 9475 0 46264256 0 14012 14172
...

$ perf stat --input perf.data

Total event stats for 'perf.data.inherit' file:

TOTAL events: 9370
MMAP events: 140
COMM events: 2
EXIT events: 401
FORK events: 400
READ events: 1600
SAMPLE events: 6806
MMAP2 events: 20
FINISHED_ROUND events: 1

Sample event stats:

2,984,107,504 cycles
6,806 samples # sampling ratio 161.107% (6444/4000)

0.264032172 second time sampled

So the cycles values on 'perf report -T' are a lot more than the value
of perf stat. And I have no idea why it shows 5 different cycles for
each thread. Could you shed some light on this?

Thanks,
Namhyung
--
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/