perf report/script: Support percent and multiple range in --time option
v3 cover perf report/script: Support percent and multiple range in --time option
v3:
---
1. Move the definitions of first_sample_time/last_sample_time from perf_session and struct record to perf_evlist and update the related code.
v2:
---
1. This patch creates a new header feature type HEADER_SAMPLE_TIME and related ops. Save the first sample time and the last sample time to the feature section in perf file header.
2. Add checking for last element in time range.
For example, select the first and second 10% time slices. perf report --time 10%/1,10%/2
Note that now it includes the last element in [10%, 20%] but it doesn't include the last element in [0, 10%). It's to avoid the overlap.
Following patches are changed:
perf header: Record first sample time and last sample time in perf file header perf record: Get the first sample time and last sample time
perf util: Create function to perform multiple time range checking
v1: initial post
----------------
Current perf report/script/... have a --time option to limit the time range of output. But it only supports the absolute time.
The patch series extend this option to let it support percent of time and support the multiple time ranges.
For example:
1. Select the second 10% time slice
perf report --time 10%/2
2. Select from 0% to 10% time slice
perf report --time 0%-10%
It also support the multiple time ranges.
3. Select the first and second 10% time slices
perf report --time 10%/1,10%/2
4. Select from 0% to 10% and 30% to 40% slices
perf report --time 0%-10%,30%-40%
Jin Yao (6):
perf header: Record first sample time and last sample time in perf
file header
perf record: Get the first sample time and last sample time perf util: Create function to parse time percent
perf util: Create function to perform multiple time range checking perf report: support time percent and multiple time ranges perf script: support time percent and multiple time ranges
tools/perf/Documentation/perf-report.txt | 16 ++ tools/perf/Documentation/perf-script.txt | 16 ++ tools/perf/Documentation/perf.data-file-format.txt | 4 + tools/perf/builtin-record.c | 5 + tools/perf/builtin-report.c | 24 ++- tools/perf/builtin-script.c | 21 +- tools/perf/util/evlist.h | 2 + tools/perf/util/header.c | 49 +++++ tools/perf/util/header.h | 1 + tools/perf/util/time-utils.c | 225 +++++++++++++++++++-- tools/perf/util/time-utils.h | 6 + 11 files changed, 352 insertions(+), 17 deletions(-)
Signature · 1 line
2.7.4
PATCH v3 1/6 perf header: Record first sample time and last sample time in perf file header
perf report/script/... have a --time option to limit the time range of output. That's very useful to slice large traces, e.g. when processing the output of perf script for some analysis.
But right now --time only supports absolute time. Also there is no fast way to get the start/end times of a given trace except for looking at it. This makes it hard to e.g. only decode the first half of the trace, which is useful for parallelization of scripts
Another problem is that perf records are variable size and there is no synchronization mechanism. So the only way to find the last sample reliably would be to walk all samples. But we want to avoid that in perf report/... because it is already quite expensive. That is why storing the first sample time and last sample time in perf record is better.
This patch creates a new header feature type HEADER_SAMPLE_TIME and related ops. Save the first sample time and the last sample time to the feature section in perf file header.
Change log:
-----------
v3: Remove the definitions of first_sample_time/last_sample_time from
perf_session. Just define them in perf_evlist
--- tools/perf/Documentation/perf.data-file-format.txt | 4 ++ tools/perf/util/evlist.h | 2 + tools/perf/util/header.c | 49 ++++++++++++++++++++++ tools/perf/util/header.h | 1 + 4 files changed, 56 insertions(+)
tools/perf/Documentation/perf.data-file-format.txt +4 -0
@@ -238,6 +238,10 @@ struct auxtrace_index { struct auxtrace_index_entry entries[PERF_AUXTRACE_INDEX_ENTRY_COUNT]; }; + HEADER_SAMPLE_TIME = 21, + +Two uint64_t for the time of first sample and the time of last sample. + other bits are reserved and should ignored for now HEADER_FEAT_BITS = 256,
tools/perf/util/evlist.h +2 -0
@@ -99,6 +99,8 @@ struct perf_evlist {struct perf_evsel *selected;struct events_stats stats;struct perf_env *env; +u64 first_sample_time; +u64 last_sample_time; };struct perf_evsel_str_handler {
tools/perf/util/header.c +49 -0
73 lines not on this page · raw message
tools/perf/util/header.h +1 -0
@@ -33,6 +33,7 @@ enum {HEADER_AUXTRACE ,HEADER_STAT ,HEADER_CACHE , +HEADER_SAMPLE_TIME ,HEADER_LAST_FEATURE , HEADER_FEAT_BITS = 256, };
Signature · 1 line
2.7.4
Re: [PATCH v3 1/6] perf header: Record first sample time and last sample time in perf file header
On Thu, Sep 28, 2017 at 08:45:16PM +0800, Jin Yao wrote:
SNIP
Quoted 14 lines
tools/perf/util/header.c +7
-0+return ret; + +return do_write (ff, &evlist->last_sample_time, +sizeof (evlist->last_sample_time)); +} +static void print_hostname (struct feat_fd *ff,FILE *fp) {fprintf (fp,"# hostname : %s\n" , ff->ph->env.hostname);@@ -1506,6 +1520,19 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp) } } +static void print_sample_time (struct feat_fd *ff,FILE *fp)
tools/perf/util/header.c static void print_group_desc(struct feat_fd *ff, FILE *fp) · line 1533
Quoted 10 lines
tools/perf/util/header.c +10
-0+{ +struct perf_session *session; + + session = container_of(ff->ph, struct perf_session, header); + +fprintf (fp,"# time of first sample : %" PRIu64"\n" , + session->evlist->first_sample_time); + +fprintf (fp,"# time of last sample : %" PRIu64"\n" , + session->evlist->last_sample_time);
this could be done in some follow up patch, but could we display this in some human readable way..
# time of first sample : 218077073264620 # time of last sample : 218077073395488
jirka
Re: [PATCH v3 1/6] perf header: Record first sample time and last sample time in perf file header
Quoted 32 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:16PM +0800, Jin Yao wrote:
SNIP
Quoted 14 lines
tools/perf/util/header.c +7
-0+return ret; + +return do_write (ff, &evlist->last_sample_time, +sizeof (evlist->last_sample_time)); +} +static void print_hostname (struct feat_fd *ff,FILE *fp) {fprintf (fp,"# hostname : %s\n" , ff->ph->env.hostname);@@ -1506,6 +1520,19 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp) } } +static void print_sample_time (struct feat_fd *ff,FILE *fp)tools/perf/util/header.c static void print_group_desc(struct feat_fd *ff, FILE *fp) · line 1533
Quoted 10 lines
tools/perf/util/header.c +10
-0+{ +struct perf_session *session; + + session = container_of(ff->ph, struct perf_session, header); + +fprintf (fp,"# time of first sample : %" PRIu64"\n" , + session->evlist->first_sample_time); + +fprintf (fp,"# time of last sample : %" PRIu64"\n" , + session->evlist->last_sample_time);this could be done in some follow up patch, but could we display this in some human readable way..
Quoted 5 lines
# time of first sample : 218077073264620 # time of last sample : 218077073395488jirka
Could I add the printing of duration? For example,
duration = (double)(last_sample_time - first_sample_time) / NSEC_PER_MSEC; fprintf(fp, "# sample duration: %10.3f (ms)\n", duration);
fprintf(fp, "# time of first sample : %" PRIu64 "\n",
first_sample_time);
fprintf(fp, "# time of last sample : %" PRIu64 "\n",
last_sample_time);
Thanks
Jin Yao
Re: [PATCH v3 1/6] perf header: Record first sample time and last sample time in perf file header
Quoted 43 lines · Yao
Quoted 32 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:16PM +0800, Jin Yao wrote:
SNIP
Quoted 14 lines
tools/perf/util/header.c +7
-0+return ret; + +return do_write (ff, &evlist->last_sample_time, +sizeof (evlist->last_sample_time)); +} +static void print_hostname (struct feat_fd *ff,FILE *fp) {fprintf (fp,"# hostname : %s\n" , ff->ph->env.hostname);@@ -1506,6 +1520,19 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp) } } +static void print_sample_time (struct feat_fd *ff,FILE *fp)tools/perf/util/header.c static void print_group_desc(struct feat_fd *ff, FILE *fp) · line 1533
Quoted 10 lines
tools/perf/util/header.c +10
-0+{ +struct perf_session *session; + + session = container_of(ff->ph, struct perf_session, header); + +fprintf (fp,"# time of first sample : %" PRIu64"\n" , + session->evlist->first_sample_time); + +fprintf (fp,"# time of last sample : %" PRIu64"\n" , + session->evlist->last_sample_time);this could be done in some follow up patch, but could we display this in some human readable way..
Quoted 5 lines
# time of first sample : 218077073264620 # time of last sample : 218077073395488jirka
Could I add the printing of duration? For example,
Quoted 8 lines
duration = (double)(last_sample_time -
first_sample_time) /NSEC_PER_MSEC;fprintf(fp, "# sample duration: %10.3f (ms)\n", duration);fprintf(fp, "# time of first sample : %" PRIu64 "\n",
first_sample_time);fprintf(fp, "# time of last sample : %" PRIu64 "\n",
last_sample_time);
could be, but mainly please display the time same way the perf script does:
218482.819815
jirka
Re: [PATCH v3 1/6] perf header: Record first sample time and last sample time in perf file header
Quoted 50 lines · Jiri Olsa
Quoted 49 lines · Yao
Quoted 32 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:16PM +0800, Jin Yao wrote:
SNIP
Quoted 14 lines
tools/perf/util/header.c +7
-0+return ret; + +return do_write (ff, &evlist->last_sample_time, +sizeof (evlist->last_sample_time)); +} +static void print_hostname (struct feat_fd *ff,FILE *fp) {fprintf (fp,"# hostname : %s\n" , ff->ph->env.hostname);@@ -1506,6 +1520,19 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp) } } +static void print_sample_time (struct feat_fd *ff,FILE *fp)tools/perf/util/header.c static void print_group_desc(struct feat_fd *ff, FILE *fp) · line 1533
Quoted 10 lines
tools/perf/util/header.c +10
-0+{ +struct perf_session *session; + + session = container_of(ff->ph, struct perf_session, header); + +fprintf (fp,"# time of first sample : %" PRIu64"\n" , + session->evlist->first_sample_time); + +fprintf (fp,"# time of last sample : %" PRIu64"\n" , + session->evlist->last_sample_time);this could be done in some follow up patch, but could we display this in some human readable way..
Quoted 5 lines
# time of first sample : 218077073264620 # time of last sample : 218077073395488jirka
Could I add the printing of duration? For example,
duration = (double)(last_sample_time -
first_sample_time) /NSEC_PER_MSEC;fprintf(fp, "# sample duration: %10.3f (ms)\n", duration);fprintf(fp, "# time of first sample : %" PRIu64 "\n",
first_sample_time);
Quoted 9 lines
Quoted 2 lines
fprintf(fp, "# time of last sample : %" PRIu64 "\n",
last_sample_time);could be, but mainly please display the time same way the perf script does:
218482.819815
jirka
Fine. I think I can use timestamp__scnprintf_usec() to print the timestamp.
BTW, do we need the duration printing here?
Thanks
Jin Yao
Re: [PATCH v3 1/6] perf header: Record first sample time and last sample time in perf file header
Quoted 58 lines · Yao
Quoted 55 lines · Jiri Olsa
Quoted 43 lines · Yao
Quoted 32 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:16PM +0800, Jin Yao wrote:
SNIP
Quoted 14 lines
tools/perf/util/header.c +7
-0+return ret; + +return do_write (ff, &evlist->last_sample_time, +sizeof (evlist->last_sample_time)); +} +static void print_hostname (struct feat_fd *ff,FILE *fp) {fprintf (fp,"# hostname : %s\n" , ff->ph->env.hostname);@@ -1506,6 +1520,19 @@ static void print_group_desc(struct feat_fd *ff, FILE *fp) } } +static void print_sample_time (struct feat_fd *ff,FILE *fp)tools/perf/util/header.c static void print_group_desc(struct feat_fd *ff, FILE *fp) · line 1533
Quoted 10 lines
tools/perf/util/header.c +10
-0+{ +struct perf_session *session; + + session = container_of(ff->ph, struct perf_session, header); + +fprintf (fp,"# time of first sample : %" PRIu64"\n" , + session->evlist->first_sample_time); + +fprintf (fp,"# time of last sample : %" PRIu64"\n" , + session->evlist->last_sample_time);this could be done in some follow up patch, but could we display this in some human readable way..
Quoted 5 lines
# time of first sample : 218077073264620 # time of last sample : 218077073395488jirka
Could I add the printing of duration? For example,
Quoted 8 lines
duration = (double)(last_sample_time -
first_sample_time) /NSEC_PER_MSEC;fprintf(fp, "# sample duration: %10.3f (ms)\n", duration);fprintf(fp, "# time of first sample : %" PRIu64 "\n",
first_sample_time);fprintf(fp, "# time of last sample : %" PRIu64 "\n",
last_sample_time);could be, but mainly please display the time same way the perf script does:
Quoted 8 lines
Quoted 4 lines
218482.819815
jirka
Fine. I think I can use
timestamp__scnprintf_usec()to print the timestamp.BTW, do we need the duration printing here?
yea, might be helpful
thanks,
jirka
PATCH v3 2/6 perf record: Get the first sample time and last sample time
In reply to Jin YaoIn perf record, it's walked on all samples yet. So it's very easy to get the first/last samples and save the time to perf file header via the function write_sample_time().
In later, perf report/script will fetch the time from perf file header.
Change log:
-----------
v3: Remove the definitions of first_sample_time and last_sample_time
from struct record and directly save them in perf_evlist.
--- tools/perf/builtin-record.c | 5 +++++ 1 file changed, 5 insertions(+)
tools/perf/builtin-record.c +5 -0
@@ -488,6 +488,11 @@ static int process_sample_event(struct perf_tool *tool, rec->samples++; +if (rec->evlist->first_sample_time ==0 ) + rec->evlist->first_sample_time = sample->time; + + rec->evlist->last_sample_time = sample->time; +return build_id__mark_dso_hit (tool, event, sample, evsel, machine); }
Signature · 1 line
2.7.4
PATCH v3 3/6 perf util: Create function to parse time percent
In reply to Jin YaoCurrent perf report/script/... have a --time option to limit the time range of output. But right now it only supports absolute time.
For easy using, now it can support a percent of time usage.
For example:
1. Select the second 10% time slice
perf report --time 10%/2
2. Select from 0% to 10% time slice
perf report --time 0%-10%
It also support the multiple time ranges.
3. Select the first and second 10% time slices
perf report --time 10%/1,10%/2
4. Select from 0% to 10% and 30% to 40% slices
perf report --time 0%-10%,30%-40%
--- tools/perf/util/time-utils.c | 203 ++++++++++++++++++++++++++++++++++++++++--- tools/perf/util/time-utils.h | 3 + 2 files changed, 194 insertions(+), 12 deletions(-)
tools/perf/util/time-utils.c +191 -12
@@ -5,6 +5,7 @@#include <time.h> #include <errno.h> #include <inttypes.h> +#include <math.h> #include "perf.h" #include "debug.h"
@@ -59,11 +60,10 @@ static int parse_timestr_sec_nsec(struct perf_time_interval *ptime,return 0 ; } -int perf_time__parse_str (struct perf_time_interval *ptime,const char *ostr) +static int split_start_end (char **start,char **end,const char *ostr,char ch) {char *start_str, *end_str;char *d, *str; -int rc =0 ;if (ostr ==NULL || *ostr =='\0' )return 0 ;
@@ -73,25 +73,35 @@ int perf_time__parse_str(struct perf_time_interval *ptime, const char *ostr)if (str ==NULL )return -ENOMEM ; - ptime->start =0 ; - ptime->end =0 ; - -/* str has the format: <start>,<stop> -* variations: <start>, -* ,<stop> -* , -*/ start_str = str; - d =strchr (start_str,',' ); + d =strchr (start_str, ch);if (d) { *d ='\0' ; ++d; } end_str = d; + *start = start_str; + *end = end_str; + +return 0 ; +} + +int perf_time__parse_str (struct perf_time_interval *ptime,const char *ostr) +{ +char *start_str =NULL , *end_str; +int rc; + + rc =split_start_end (&start_str, &end_str, ostr,',' ); +if (rc || !start_str) +return rc; + + ptime->start =0 ; + ptime->end =0 ; + rc =parse_timestr_sec_nsec (ptime, start_str, end_str); -free (str); +free (start_str);/* make sure end time is after start time if it was given */ if (rc ==0 && ptime->end && ptime->end < ptime->start)
@@ -103,6 +113,175 @@ int perf_time__parse_str(struct perf_time_interval *ptime, const char *ostr)return rc; } +static int parse_percent (double *pcnt,char *str) +{ +char *c; + + c =strchr (str,'%' ); +if (c) + *c ='\0' ; +else +return -1 ; + + *pcnt =atof (str) /100.0 ; + +return 0 ; +} + +static int percent_slash_split (char *str,struct perf_time_interval *ptime, +u64 start,u64 end) +{ +char *p; +double pcnt, start_pcnt, end_pcnt; +u64 total = end - start; +int i; + +/* +* Example: +* 10%/2: select the second 10% slice and the third 10% slice +*/ + +/* We can modify this string since the original one is copied */ + p =strchr (str,'/' ); +if (!p) +return -1 ; + + *p ='\0' ; +if (parse_percent (&pcnt, str) <0 ) +return -1 ; + + p++; + i =atoi (p); + +if (pcnt <=0.0 ) +return -1 ; + + start_pcnt = pcnt * (i -1 ); + end_pcnt = pcnt * i; + +if (start_pcnt <0.0 || start_pcnt >1.0 || + end_pcnt <0.0 || end_pcnt >1.0 ) { +return -1 ; + } + + ptime->start = start +round (start_pcnt * total); + ptime->end = start +round (end_pcnt * total); + +return 0 ; +} + +static int percent_dash_split (char *str,struct perf_time_interval *ptime, +u64 start,u64 end) +{ +char *start_str =NULL , *end_str; +double start_pcnt, end_pcnt; +u64 total = end - start; +int ret; + +/* +* Example: 0%-10% +*/ + + ret =split_start_end (&start_str, &end_str, str,'-' ); +if (ret || !start_str) +return ret; + +if ((parse_percent (&start_pcnt, start_str) !=0 ) || + (parse_percent (&end_pcnt, end_str) !=0 )) { +free (start_str); +return -1 ; + } + +free (start_str); + +if (start_pcnt <0.0 || start_pcnt >1.0 || + end_pcnt <0.0 || end_pcnt >1.0 || + start_pcnt > end_pcnt) { +return -1 ; + } + + ptime->start = start +round (start_pcnt * total); + ptime->end = start +round (end_pcnt * total); + +return 0 ; +} + +typedef int (*time_pecent_split )(char *,struct perf_time_interval *, +u64 start,u64 end); + +static int percent_comma_split (struct perf_time_interval *ptime_buf,int num, +const char *ostr,u64 start,u64 end, +time_pecent_split func) +{ +char *str, *p1, *p2; +int len, ret, i =0 ; + + str =strdup (ostr); +if (str ==NULL ) +return -ENOMEM ; + + len =strlen (str); + p1 = str; + +while (p1 < str + len) { +if (i >= num) { +free (str); +return -1 ; + } + + p2 =strchr (p1,',' ); +if (p2) + *p2 ='\0' ; + + ret = (func)(p1, &ptime_buf[i], start, end); +if (ret <0 ) { +free (str); +return -1 ; + } + +pr_debug ("start time %d: %" PRIu64", " , i, ptime_buf[i].start); +pr_debug ("end time %d: %" PRIu64"\n" , i, ptime_buf[i].end); + + i++; + +if (p2) + p1 = p2 +1 ; +else +break ; + } + +free (str); +return i; +} + +int perf_time__percent_parse_str (struct perf_time_interval *ptime_buf,int num, +const char *ostr,u64 start,u64 end) +{ +char *c; + +/* +* ostr example: +* 10%/2,10%/3: select the second 10% slice and the third 10% slice +* 0%-10%,30%-40%: multiple time range +*/ + +memset (ptime_buf,0 ,sizeof (*ptime_buf) * num); + + c =strchr (ostr,'/' ); +if (c) { +return percent_comma_split (ptime_buf, num, ostr, start, + end, percent_slash_split); + } + + c =strchr (ostr,'-' ); +if (c) { +return percent_comma_split (ptime_buf, num, ostr, start, + end, percent_dash_split); + } + +return -1 ; +} +bool perf_time__skip_sample (struct perf_time_interval *ptime,u64 timestamp) {/* if time is not set don't drop sample */
tools/perf/util/time-utils.h +3 -0
@@ -12,6 +12,9 @@ int parse_nsec_time(const char *str, u64 *ptime);int perf_time__parse_str (struct perf_time_interval *ptime,const char *ostr); +int perf_time__percent_parse_str (struct perf_time_interval *ptime_buf,int num, +const char *ostr,u64 start,u64 end); +bool perf_time__skip_sample (struct perf_time_interval *ptime,u64 timestamp);int timestamp__scnprintf_usec (u64 timestamp,char *buf,size_t sz);
Signature · 1 line
2.7.4
PATCH v3 4/6 perf util: Create function to perform multiple time range checking
In reply to Jin YaoPrevious patch supports the multiple time range.
For example, select the first and second 10% time slices. perf report --time 10%/1,10%/2
We need a function to check if a timestamp is in the ranges of [0, 10%) and [10%, 20%].
Note that it includes the last element in [10%, 20%] but it doesn't include the last element in [0, 10%). It's to avoid the overlap.
This patch implments a new function perf_time__ranges_skip_sample for this checking.
--- tools/perf/util/time-utils.c | 22 ++++++++++++++++++++++ tools/perf/util/time-utils.h | 3 +++ 2 files changed, 25 insertions(+)
tools/perf/util/time-utils.c +22 -0
@@ -297,6 +297,28 @@ bool perf_time__skip_sample(struct perf_time_interval *ptime, u64 timestamp)return false; } +bool perf_time__ranges_skip_sample (struct perf_time_interval *ptime_buf, +int num,u64 timestamp) +{ +struct perf_time_interval *ptime; +int i; + +if ((timestamp ==0 ) || (num ==0 )) +return false; + +for (i =0 ; i < num; i++) { + ptime = &ptime_buf[i]; + +if (timestamp >= ptime->start && + ((timestamp < ptime->end && i < num -1 ) || + (timestamp <= ptime->end && i == num -1 ))) { +break ; + } + } + +return (i == num) ? true : false; +} +int timestamp__scnprintf_usec (u64 timestamp,char *buf,size_t sz) {u64 sec = timestamp /NSEC_PER_SEC ;
tools/perf/util/time-utils.h +3 -0
@@ -17,6 +17,9 @@ int perf_time__percent_parse_str(struct perf_time_interval *ptime_buf, int num,bool perf_time__skip_sample (struct perf_time_interval *ptime,u64 timestamp); +bool perf_time__ranges_skip_sample (struct perf_time_interval *ptime_buf, +int num,u64 timestamp); +int timestamp__scnprintf_usec (u64 timestamp,char *buf,size_t sz);int fetch_current_timestamp (char *buf,size_t sz);
Signature · 1 line
2.7.4
PATCH v3 5/6 perf report: support time percent and multiple time ranges
In reply to Jin Yaoperf 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
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.
--- tools/perf/Documentation/perf-report.txt | 16 ++++++++++++++++ tools/perf/builtin-report.c | 24 ++++++++++++++++++++++-- 2 files changed, 38 insertions(+), 2 deletions(-)
tools/perf/Documentation/perf-report.txt +16 -0
@@ -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:
tools/perf/builtin-report.c +22 -2
@@ -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 ; }
Signature · 1 line
2.7.4
Re: [PATCH v3 5/6] perf report: support time percent and multiple time ranges
Quoted 10 lines · Jin Yao
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
Quoted 103 lines
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 fromperf_sessiontoperf_evlistso change the related code.Signed-off-by Jin Yao <[email protected]>--- tools/perf/Documentation/perf-report.txt | 16 ++++++++++++++++ tools/perf/builtin-report.c | 24 ++++++++++++++++++++++-- 2 files changed, 38 insertions(+), 2 deletions(-)tools/perf/Documentation/perf-report.txt +16
-0@@ -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:tools/perf/builtin-report.c +22
-2@@ -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 ; }Signature · 1 line
2.7.4
Re: [PATCH v3 5/6] perf report: support time percent and multiple time ranges
Quoted 26 lines · Jiri Olsa
Quoted 10 lines · Jin Yao
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%/2hum, 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)
Quoted 4 lines
please add a test for this
jirka
Sorry, I will add test for checking this case.
Thanks
Jin Yao
PATCH v3 6/6 perf script: support time percent and multiple time ranges
In reply to Jin Yaoperf script 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 script --time 10%/1,10%/2
2. Select from 0% to 10% and 30% to 40% slices
perf script --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.
--- tools/perf/Documentation/perf-script.txt | 16 ++++++++++++++++ tools/perf/builtin-script.c | 21 ++++++++++++++++++--- 2 files changed, 34 insertions(+), 3 deletions(-)
tools/perf/Documentation/perf-script.txt +16 -0
@@ -321,6 +321,22 @@ include::itrace.txt[] 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 script --time 10%/2 + + Select from 0% to 10% time slice + perf script --time 0%-10% + + Select the first and second 10% time slices + perf script --time 10%/1,10%/2 + + Select from 0% to 10% and 30% to 40% slices + perf script --time 0%-10%,30%-40% + --max-blocks:: Set the maximum number of program blocks to print with brstackasm for each sample.
tools/perf/builtin-script.c +18 -3
@@ -1357,6 +1357,8 @@ static void print_sample_synth(struct perf_sample *sample, } } +#define PTIME_RANGE_MAX 10 +struct perf_script {struct perf_tool tool;struct perf_session *session;
@@ -1370,6 +1372,8 @@ struct perf_script {int name_width;const char *time_str;struct perf_time_interval ptime; +struct perf_time_interval ptime_range[PTIME_RANGE_MAX ]; +int range_num; };static int perf_evlist__max_name_len (struct perf_evlist *evlist)
@@ -1565,8 +1569,11 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool);struct addr_location al; -if (perf_time__skip_sample (&scr->ptime, sample->time)) +if (perf_time__skip_sample (&scr->ptime, sample->time) || +perf_time__ranges_skip_sample (scr->ptime_range, scr->range_num, + sample->time)) {return 0 ; + }if (debug_mode) {if (sample->time < last_timestamp) {
@@ -3104,8 +3111,16 @@ int cmd_script(int argc, const char **argv)/* needs to be parsed after looking up reference time */ if (perf_time__parse_str (&script.ptime, script.time_str) !=0 ) { -pr_err ("Invalid time string\n" ); -return -EINVAL ; + script.range_num =perf_time__percent_parse_str ( + script.ptime_range,PTIME_RANGE_MAX , + script.time_str, + session->evlist->first_sample_time, + session->evlist->last_sample_time); + +if (script.range_num <0 ) { +pr_err ("Invalid time string\n" ); +return -EINVAL ; + } } err =__cmd_script (&script);
Signature · 1 line
2.7.4
Re: [PATCH v3 6/6] perf script: support time percent and multiple time ranges
On Thu, Sep 28, 2017 at 08:45:21PM +0800, Jin Yao wrote:
SNIP
Quoted 23 lines
tools/perf/builtin-script.c +4
-0@@ -1357,6 +1357,8 @@ static void print_sample_synth(struct perf_sample *sample, } } +#define PTIME_RANGE_MAX 10 +struct perf_script {struct perf_tool tool;struct perf_session *session;@@ -1370,6 +1372,8 @@ struct perf_script {int name_width;const char *time_str;struct perf_time_interval ptime; +struct perf_time_interval ptime_range[PTIME_RANGE_MAX ]; +int range_num; };static int perf_evlist__max_name_len (struct perf_evlist *evlist)
tools/perf/builtin-script.c static int process_sample_event(struct perf_tool *tool, · line 1574
Quoted 7 lines
tools/perf/builtin-script.c +3
-1@@ -1565,8 +1569,11 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool);struct addr_location al; -if (perf_time__skip_sample (&scr->ptime, sample->time)) +if (perf_time__skip_sample (&scr->ptime, sample->time) || +perf_time__ranges_skip_sample (scr->ptime_range, scr->range_num, + sample->time)) {
any reason for why dont use ptime_range[1] with range_num = 1 and use just a single call here?
jirka
Re: [PATCH v3 6/6] perf script: support time percent and multiple time ranges
Quoted 38 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:21PM +0800, Jin Yao wrote:
SNIP
Quoted 23 lines
tools/perf/builtin-script.c +4
-0@@ -1357,6 +1357,8 @@ static void print_sample_synth(struct perf_sample *sample, } } +#define PTIME_RANGE_MAX 10 +struct perf_script {struct perf_tool tool;struct perf_session *session;@@ -1370,6 +1372,8 @@ struct perf_script {int name_width;const char *time_str;struct perf_time_interval ptime; +struct perf_time_interval ptime_range[PTIME_RANGE_MAX ]; +int range_num; };static int perf_evlist__max_name_len (struct perf_evlist *evlist)tools/perf/builtin-script.c static int process_sample_event(struct perf_tool *tool, · line 1574
Quoted 7 lines
tools/perf/builtin-script.c +3
-1@@ -1565,8 +1569,11 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool);struct addr_location al; -if (perf_time__skip_sample (&scr->ptime, sample->time)) +if (perf_time__skip_sample (&scr->ptime, sample->time) || +perf_time__ranges_skip_sample (scr->ptime_range, scr->range_num, + sample->time)) {any reason for why dont use ptime_range[1] with
range_num= 1 and use just a single call here?
Quoted 2 lines
jirka
Just want the code to be easy reading.
perf_time__range_skip_sample doesn't allow the invalid time range.
But perf_time__skip_sample allows the time range to be invalid (ptime->start or ptime->end can be 0).
I don't want to mix them up because the code might be not clear.
Are 2 calls OK here? If you think a single call is better, I will change.
Thanks
Jin Yao
Re: [PATCH v3 6/6] perf script: support time percent and multiple time ranges
Quoted 46 lines · Yao
Quoted 38 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:21PM +0800, Jin Yao wrote:
SNIP
Quoted 23 lines
tools/perf/builtin-script.c +4
-0@@ -1357,6 +1357,8 @@ static void print_sample_synth(struct perf_sample *sample, } } +#define PTIME_RANGE_MAX 10 +struct perf_script {struct perf_tool tool;struct perf_session *session;@@ -1370,6 +1372,8 @@ struct perf_script {int name_width;const char *time_str;struct perf_time_interval ptime; +struct perf_time_interval ptime_range[PTIME_RANGE_MAX ]; +int range_num; };static int perf_evlist__max_name_len (struct perf_evlist *evlist)tools/perf/builtin-script.c static int process_sample_event(struct perf_tool *tool, · line 1574
Quoted 7 lines
tools/perf/builtin-script.c +3
-1@@ -1565,8 +1569,11 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool);struct addr_location al; -if (perf_time__skip_sample (&scr->ptime, sample->time)) +if (perf_time__skip_sample (&scr->ptime, sample->time) || +perf_time__ranges_skip_sample (scr->ptime_range, scr->range_num, + sample->time)) {any reason for why dont use ptime_range[1] with
range_num= 1 and use just a single call here?Quoted 2 lines
jirka
Just want the code to be easy reading.
Quoted 7 lines
perf_time__range_skip_sampledoesn't allow the invalid time range.But
perf_time__skip_sampleallows the time range to be invalid (ptime->startorptime->endcan be 0).I don't want to mix them up because the code might be not clear.
Are 2 calls OK here? If you think a single call is better, I will change.
well, would be nice to have single call for this.. but not big deal for me ;-)
jirka
Re: [PATCH v3 6/6] perf script: support time percent and multiple time ranges
Quoted 51 lines · Jiri Olsa
Quoted 50 lines · Yao
Quoted 38 lines · Jiri Olsa
On Thu, Sep 28, 2017 at 08:45:21PM +0800, Jin Yao wrote:
SNIP
Quoted 23 lines
tools/perf/builtin-script.c +4
-0@@ -1357,6 +1357,8 @@ static void print_sample_synth(struct perf_sample *sample, } } +#define PTIME_RANGE_MAX 10 +struct perf_script {struct perf_tool tool;struct perf_session *session;@@ -1370,6 +1372,8 @@ struct perf_script {int name_width;const char *time_str;struct perf_time_interval ptime; +struct perf_time_interval ptime_range[PTIME_RANGE_MAX ]; +int range_num; };static int perf_evlist__max_name_len (struct perf_evlist *evlist)tools/perf/builtin-script.c static int process_sample_event(struct perf_tool *tool, · line 1574
Quoted 7 lines
tools/perf/builtin-script.c +3
-1@@ -1565,8 +1569,11 @@ static int process_sample_event(struct perf_tool *tool, struct perf_script *scr = container_of(tool, struct perf_script, tool);struct addr_location al; -if (perf_time__skip_sample (&scr->ptime, sample->time)) +if (perf_time__skip_sample (&scr->ptime, sample->time) || +perf_time__ranges_skip_sample (scr->ptime_range, scr->range_num, + sample->time)) {any reason for why dont use ptime_range[1] with
range_num= 1 and use just a single call here?Quoted 2 lines
jirka
Just want the code to be easy reading.
perf_time__range_skip_sampledoesn't allow the invalid time range.But
perf_time__skip_sampleallows the time range to be invalid (ptime->startorptime->endcan be 0).
Quoted 8 lines
Quoted 3 lines
I don't want to mix them up because the code might be not clear.
Are 2 calls OK here? If you think a single call is better, I will change.
well, would be nice to have single call for this.. but not big deal for me ;-)
jirka
I will make a single call for this.
Thanks
Jin Yao