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

[Namhyung Kim]

Hi Jiri,

On Wed, Apr 29, 2015 at 4:42 PM, Jiri Olsa <jolsa@xxxxxxxxxx> 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
>
> nice, but maybe I'd see this under 'perf data' command, like:
>
>     $ perf data --stat
>
> 'perf stat' does not deal with sampling..  I think that 'perf data'
> is for perf.data related stuff like:
>
>   perf data convert ...
>   perf data ls
>   perf data --features
>   perf data --stat
>   ...
>
> thoughts? ;-)

Well, I don't mind where this feature goes into.  :)

Actually I first thought to implement this in 'perf report --stat' as
it deals with samples.  But then changed my mind to go with 'perf
stat' because it's the command for showing stat result and the sample
processing required for this feature is trivial.  Also I tried to
match the output format to normal 'perf stat'.

Thanks,
Namhyung


>
> jirka
>
>>
>>     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
>>
>> The sampling ratio was useful for me to determine how often the event
>> was sampled - in this case the cpu cycles event was only sampled at 12%
>> of the expected sampling frequency, so the system was mostly idle in
>> terms of cpu cycles (or the event was multiplexed in case of recording
>> large number of events at once).
>>
>> The sampling ratio was calulated like below:
>>
>>   expected_freq  = evsel->attr.sample_freq
>>   actual_freq    = (nr_samples / nr_cpus) / sample_time
>>   sampling_ratio = 100 * actual_freq / expected_freq
>>
>> Cc: Minchan Kim <minchan@xxxxxxxxxx>
>> Signed-off-by: Namhyung Kim <namhyung@xxxxxxxxxx>
>> ---
>>  tools/perf/builtin-stat.c | 91 +++++++++++++++++++++++++++++++++++++++++++++--
>>  1 file changed, 89 insertions(+), 2 deletions(-)
>>
>> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
>> index fd577f725d23..78ded82df4a9 100644
>> --- a/tools/perf/builtin-stat.c
>> +++ b/tools/perf/builtin-stat.c
>> @@ -58,6 +58,7 @@
>>  #include "util/cpumap.h"
>>  #include "util/thread.h"
>>  #include "util/thread_map.h"
>> +#include "util/hist.h"
>>
>>  #include <stdlib.h>
>>  #include <sys/prctl.h>
>> @@ -1576,6 +1577,87 @@ static int perf_stat_init_aggr_mode(void)
>>       return 0;
>>  }
>>
>> +static u64 first_sample_nsec;
>> +static u64 last_sample_nsec;
>> +
>> +static int process_sample_event(struct perf_tool *tool __maybe_unused,
>> +                             union perf_event *event __maybe_unused,
>> +                             struct perf_sample *sample,
>> +                             struct perf_evsel *evsel,
>> +                             struct machine *machine __maybe_unused)
>> +{
>> +     struct hists *hists = evsel__hists(evsel);
>> +
>> +     if (!first_sample_nsec)
>> +             first_sample_nsec = sample->time;
>> +     last_sample_nsec = sample->time;
>> +
>> +     hists->stats.total_period += sample->period;
>> +     hists->stats.nr_events[PERF_RECORD_SAMPLE]++;
>> +     return 0;
>> +}
>> +
>> +static int show_sample_stat(void)
>> +{
>> +     struct perf_data_file file = {
>> +             .mode  = PERF_DATA_MODE_READ,
>> +             .path  = input_name,
>> +     };
>> +     struct perf_tool tool = {
>> +             .sample = process_sample_event,
>> +     };
>> +     struct perf_session *session;
>> +     struct perf_evsel *evsel;
>> +     u64 sample_nsec;
>> +     int nr_cpus;
>> +     int ret;
>> +
>> +     session = perf_session__new(&file, false, &tool);
>> +     if (session == NULL)
>> +             return -1;
>> +
>> +     ret = perf_session__process_events(session);
>> +     if (ret < 0)
>> +             return ret;
>> +
>> +     nr_cpus = session->header.env.nr_cpus_online;
>> +     sample_nsec = last_sample_nsec - first_sample_nsec;
>> +
>> +     fprintf(output, "\n Total event stats for '%s' file:\n\n", input_name);
>> +     events_stats__fprintf(&session->evlist->stats, output);
>> +
>> +     fprintf(output, "\n Sample event stats:\n\n");
>> +     evlist__for_each(session->evlist, evsel) {
>> +             struct hists *hists = evsel__hists(evsel);
>> +             struct events_stats *stats = &hists->stats;
>> +             u64 total_period = stats->total_period;
>> +             u32 nr_samples = stats->nr_events[PERF_RECORD_SAMPLE];
>> +
>> +             fprintf(output, "%'18"PRIu64"      ", total_period);
>> +             fprintf(output, "%-25s", perf_evsel__name(evsel));
>> +             fprintf(output, "\n");
>> +             fprintf(output, "%'18u      ", nr_samples);
>> +             fprintf(output, "%-25s", "samples");
>> +
>> +             if (sample_nsec && evsel->attr.freq && evsel->attr.sample_freq) {
>> +                     int expected_rate = evsel->attr.sample_freq;
>> +                     double sample_rate = 1.0 * nr_samples / nr_cpus;
>> +
>> +                     sample_rate *= (double)NSEC_PER_SEC / sample_nsec;
>> +                     fprintf(output, " #   sampling ratio  %.3f%% (%d/%d)",
>> +                             100 * sample_rate / expected_rate,
>> +                             (int)sample_rate, expected_rate);
>> +             }
>> +             fprintf(output, "\n\n");
>> +     }
>> +
>> +     fprintf(output, "%18.9f second time sampled\n",
>> +             (double)sample_nsec / NSEC_PER_SEC);
>> +
>> +     perf_session__delete(session);
>> +     return 0;
>> +}
>> +
>>  static int setup_events(const char * const *attrs, unsigned len)
>>  {
>>       unsigned i;
>> @@ -1793,6 +1875,7 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
>>                  "print counts with custom separator"),
>>       OPT_CALLBACK('G', "cgroup", &evsel_list, "name",
>>                    "monitor event in cgroup name only", parse_cgroups),
>> +     OPT_STRING(0, "input", &input_name, "file", "input file name"),
>>       OPT_STRING('o', "output", &output_name, "file", "output file name"),
>>       OPT_BOOLEAN(0, "append", &append_file, "append to the output file"),
>>       OPT_INTEGER(0, "log-fd", &output_fd,
>> @@ -1886,8 +1969,12 @@ int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused)
>>       } else if (big_num_opt == 0) /* User passed --no-big-num */
>>               big_num = false;
>>
>> -     if (!argc && target__none(&target))
>> -             usage_with_options(stat_usage, options);
>> +     if (!argc && target__none(&target)) {
>> +             if (!input_name)
>> +                     usage_with_options(stat_usage, options);
>> +             status = show_sample_stat();
>> +             goto out;
>> +     }
>>
>>       if (run_count < 0) {
>>               pr_err("Run count must be a positive number\n");
>> --
>> 2.3.5
>>
--
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/