• [PATCH v3 5/6] perf report: support time percent and multiple time

    From Jiri Olsa@21:1/5 to Jin Yao on Mon Oct 2 14:00:01 2017
    On Thu, Sep 28, 2017 at 08:45:20PM +0800, Jin Yao wrote:
    perf report has a --time option to limit the time range of output.
    It only supports absolute time.

    Now this option is extended to support multiple time ranges and
    support the percent of time.

    For example:

    1. Select the first and second 10% time slices
    perf report --time 10%/1,10%/2

    hum, this one passes:

    [jolsa@krava perf]$ ./perf script --time 10%/10x12321xsdfdasfdsafdsafdsa
    yes 20923 218485.067881: 9263754 cycles:ppp: ffffffffa4263cca __vfs_write ([kernel.kallsyms])
    yes 20923 218485.070805: 6734429666984 cycles:ppp: ffffffffa42659e3 sys_write ([kernel.kallsyms])
    yes 20923 218485.181272: 6927427 cycles:ppp: ffffffffa42643b3 vfs_write ([kernel.kallsyms])
    yes 20923 218485.183446: 7696489147307 cycles:ppp: ffffffffa442a9ee lockref_put_return ([kernel.kallsyms])
    yes 20923 218485.292921: 9265358 cycles:ppp: 5648b27c63b0 _init (/usr/bin/yes)
    yes 20923 218485.295866: 6734429665913 cycles:ppp: ffffffffa42641b7 rw_verify_area ([kernel.kallsyms])
    yes 20923 218485.406225: 6930289 cycles:ppp: ffffffffa42ab8dd __fsnotify_parent ([kernel.kallsyms])
    yes 20923 218485.408399: 7696489149499 cycles:ppp: ffffffffa426418f rw_verify_area ([kernel.kallsyms])
    yes 20923 218485.517885: 9266280 cycles:ppp: ffffffffa42ab926 __fsnotify_parent ([kernel.kallsyms])
    yes 20923 218485.520860: 6734429663933 cycles:ppp: 5648b27c6ccb full_write (/usr/bin/yes)

    please add a test for this

    jirka


    2. Select from 0% to 10% and 30% to 40% slices
    perf report --time 0%-10%,30%-40%

    Change log:
    -----------
    v3: Since the definitions of first_sample_time/last_sample_time
    are moved from perf_session to perf_evlist so change the
    related code.

    Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
    ---
    tools/perf/Documentation/perf-report.txt | 16 ++++++++++++++++
    tools/perf/builtin-report.c | 24 ++++++++++++++++++++++--
    2 files changed, 38 insertions(+), 2 deletions(-)

    diff --git a/tools/perf/Documentation/perf-report.txt b/tools/perf/Documentation/perf-report.txt
    index 383a98d..3a0975c 100644
    --- a/tools/perf/Documentation/perf-report.txt
    +++ b/tools/perf/Documentation/perf-report.txt
    @@ -402,6 +402,22 @@ OPTIONS
    stop time is not given (i.e, time string is 'x.y,') then analysis goes
    to end of file.

    + Also support time percent with multipe time range. Time string is
    + 'a%/n,b%/m,...' or 'a%-b%,c%-%d,...'. The maximum number of slices is 10.
    +
    + For example:
    + Select the second 10% time slice
    + perf report --time 10%/2
    +
    + Select from 0% to 10% time slice
    + perf report --time 0%-10%
    +
    + Select the first and second 10% time slices
    + perf report --time 10%/1,10%/2
    +
    + Select from 0% to 10% and 30% to 40% slices
    + perf report --time 0%-10%,30%-40%
    +
    --itrace::
    Options for decoding instruction tracing data. The options are:

    diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
    index f9dff65..4776f85 100644
    --- a/tools/perf/builtin-report.c
    +++ b/tools/perf/builtin-report.c
    @@ -51,6 +51,8 @@
    #include <sys/stat.h>
    #include <unistd.h>

    +#define PTIME_RANGE_MAX 10
    +
    struct report {
    struct perf_tool tool;
    struct perf_session *session;
    @@ -69,6 +71,8 @@ struct report {
    const char *symbol_filter_str;
    const char *time_str;
    struct perf_time_interval ptime;
    + struct perf_time_interval ptime_range[PTIME_RANGE_MAX];
    + int range_num;
    float min_percent;
    u64 nr_entries;
    u64 queue_size;
    @@ -185,8 +189,11 @@ static int process_sample_event(struct perf_tool *tool,
    };
    int ret = 0;

    - if (perf_time__skip_sample(&rep->ptime, sample->time))
    + if (perf_time__skip_sample(&rep->ptime, sample->time) ||
    + perf_time__ranges_skip_sample(rep->ptime_range, rep->range_num,
    + sample->time)) {
    return 0;
    + }

    if (machine__resolve(machine, &al, sample) < 0) {
    pr_debug("problem processing %d event, skipping it.\n",
    @@ -1074,7 +1081,20 @@ int cmd_report(int argc, const char **argv)
    goto error;

    if (perf_time__parse_str(&report.ptime, report.time_str) != 0) {
    - pr_err("Invalid time string\n");
    + report.range_num = perf_time__percent_parse_str(
    + report.ptime_range, PTIME_RANGE_MAX,
    + report.time_str,
    + session->evlist->first_sample_time,
    + session->evlist->last_sample_time);
    +
    + if (report.range_num < 0) {
    + pr_err("Invalid time string\n");
    + return -EINVAL;
    + }
    + }
    +
    + if (report.range_num > 0 && perf_data_file__is_pipe(session->file)) {
    + pr_err("Time percent range is not supported in pipe\n");
    return -EINVAL;
    }

    --
    2.7.4


    --- SoupGate-Win32 v1.05
    * Origin: fsxNet Usenet Gateway (21:1/5)
  • From Jin, Yao@21:1/5 to Jiri Olsa on Mon Oct 2 15:00:02 2017
    On 10/2/2017 7:52 PM, Jiri Olsa wrote:
    On Thu, Sep 28, 2017 at 08:45:20PM +0800, Jin Yao wrote:
    perf report has a --time option to limit the time range of output.
    It only supports absolute time.

    Now this option is extended to support multiple time ranges and
    support the percent of time.

    For example:

    1. Select the first and second 10% time slices
    perf report --time 10%/1,10%/2

    hum, this one passes:

    [jolsa@krava perf]$ ./perf script --time 10%/10x12321xsdfdasfdsafdsafdsa
    yes 20923 218485.067881: 9263754 cycles:ppp: ffffffffa4263cca __vfs_write ([kernel.kallsyms])
    yes 20923 218485.070805: 6734429666984 cycles:ppp: ffffffffa42659e3 sys_write ([kernel.kallsyms])
    yes 20923 218485.181272: 6927427 cycles:ppp: ffffffffa42643b3 vfs_write ([kernel.kallsyms])
    yes 20923 218485.183446: 7696489147307 cycles:ppp: ffffffffa442a9ee lockref_put_return ([kernel.kallsyms])
    yes 20923 218485.292921: 9265358 cycles:ppp: 5648b27c63b0 _init (/usr/bin/yes)
    yes 20923 218485.295866: 6734429665913 cycles:ppp: ffffffffa42641b7 rw_verify_area ([kernel.kallsyms])
    yes 20923 218485.406225: 6930289 cycles:ppp: ffffffffa42ab8dd __fsnotify_parent ([kernel.kallsyms])
    yes 20923 218485.408399: 7696489149499 cycles:ppp: ffffffffa426418f rw_verify_area ([kernel.kallsyms])
    yes 20923 218485.517885: 9266280 cycles:ppp: ffffffffa42ab926 __fsnotify_parent ([kernel.kallsyms])
    yes 20923 218485.520860: 6734429663933 cycles:ppp: 5648b27c6ccb full_write (/usr/bin/yes)

    please add a test for this

    jirka


    Sorry, I will add test for checking this case.

    Thanks
    Jin Yao

    --- SoupGate-Win32 v1.05
    * Origin: fsxNet Usenet Gateway (21:1/5)