Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1735584 > unrolled thread

[PATCH v1 0/6] perf report/script: Support percent and multiple range in --time option

Back to article view | Back to linux.kernel

Contents

  [PATCH v1 0/6] perf report/script: Support percent and multiple range in --time option Jin Yao <yao.jin@linux.intel.com> - 2017-09-20 09:20 +0200
    [PATCH v1 1/6] perf record: Record the first sample time and last sample time to perf file header Jin Yao <yao.jin@linux.intel.com> - 2017-09-20 09:20 +0200
      Re: [PATCH v1 1/6] perf record: Record the first sample time and  last sample time to perf file header Jiri Olsa <jolsa@redhat.com> - 2017-09-21 17:20 +0200
      Re: [PATCH v1 1/6] perf record: Record the first sample time and  last sample time to perf file header Jiri Olsa <jolsa@redhat.com> - 2017-09-21 17:20 +0200
        Re: [PATCH v1 1/6] perf record: Record the first sample time and  last sample time to perf file header Jiri Olsa <jolsa@redhat.com> - 2017-09-21 17:30 +0200
          Re: [PATCH v1 1/6] perf record: Record the first sample time and last  sample time to perf file header "Jin, Yao" <yao.jin@linux.intel.com> - 2017-09-22 02:50 +0200
    [PATCH v1 6/6] perf script: support time percent and multiple time ranges Jin Yao <yao.jin@linux.intel.com> - 2017-09-20 09:20 +0200
    [PATCH v1 2/6] perf Documentation: Update perf.data-file-format.txt Jin Yao <yao.jin@linux.intel.com> - 2017-09-20 09:20 +0200

#1735584 — [PATCH v1 0/6] perf report/script: Support percent and multiple range in --time option

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 record: Record the first sample time and last sample time to perf
    file header
  perf Documentation: Update perf.data-file-format.txt
  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 |  27 ++-
 tools/perf/builtin-record.c                        |  15 ++
 tools/perf/builtin-report.c                        |  24 ++-
 tools/perf/builtin-script.c                        |  21 +-
 tools/perf/util/header.c                           |  59 +++++-
 tools/perf/util/header.h                           |   4 +
 tools/perf/util/session.h                          |   2 +
 tools/perf/util/time-utils.c                       | 224 +++++++++++++++++++--
 tools/perf/util/time-utils.h                       |   6 +
 11 files changed, 383 insertions(+), 31 deletions(-)

-- 
2.7.4

[toc] | [next] | [standalone]

#1735589 — [PATCH v1 1/6] perf record: Record the first sample time and last sample time to 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.

In perf record, it's walked on all samples yet. So it's very easy to get
the first/last samples and save the times in perf file header.

In later, perf record/script will fetch the time from perf file header.

Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
---
 tools/perf/builtin-record.c | 15 ++++++++++++
 tools/perf/util/header.c    | 59 ++++++++++++++++++++++++++++++++++++++++++---
 tools/perf/util/header.h    |  4 +++
 tools/perf/util/session.h   |  2 ++
 4 files changed, 77 insertions(+), 3 deletions(-)

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 9b379f3..72be480 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -80,6 +80,8 @@ struct record {
 	bool			timestamp_filename;
 	struct switch_output	switch_output;
 	unsigned long long	samples;
+	u64			first_sample_time;
+	u64			last_sample_time;
 };
 
 static volatile int auxtrace_record__snapshot_started;
@@ -488,6 +490,11 @@ static int process_sample_event(struct perf_tool *tool,
 
 	rec->samples++;
 
+	if (rec->first_sample_time == 0)
+		rec->first_sample_time = sample->time;
+
+	rec->last_sample_time = sample->time;
+
 	return build_id__mark_dso_hit(tool, event, sample, evsel, machine);
 }
 
@@ -1201,6 +1208,14 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 
 	perf_hooks__invoke_record_end();
 
+	if (!err && !file->is_pipe) {
+		err = perf_header__update_sample_time(fd,
+						      rec->first_sample_time,
+						      rec->last_sample_time);
+		if (err < 0)
+			goto out_child;
+	}
+
 	if (!err && !quiet) {
 		char samples[128];
 		const char *postfix = rec->timestamp_filename ?
diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c
index 605bbd5..66c9b3e 100644
--- a/tools/perf/util/header.c
+++ b/tools/perf/util/header.c
@@ -2277,6 +2277,37 @@ int perf_header__fprintf_info(struct perf_session *session, FILE *fp, bool full)
 	return 0;
 }
 
+int perf_header__update_sample_time(int fd, u64 first_time, u64 last_time)
+{
+	struct perf_file_header header;
+	struct feat_fd ff;
+	off_t tmp;
+	ssize_t ret;
+	int err = -1;
+
+	tmp = lseek(fd, 0, SEEK_CUR);
+
+	lseek(fd, 0, SEEK_SET);
+	ret = readn(fd, &header, sizeof(header));
+	if (ret < 0)
+		goto exit;
+
+	header.first_sample_time = first_time;
+	header.last_sample_time = last_time;
+
+	lseek(fd, 0, SEEK_SET);
+	ff = (struct feat_fd){ .fd = fd};
+	err = do_write(&ff, &header, sizeof(header));
+	if (err < 0)
+		goto exit;
+
+	err = 0;
+
+exit:
+	lseek(fd, tmp, SEEK_SET);
+	return err;
+}
+
 static int do_write_feat(struct feat_fd *ff, int type,
 			 struct perf_file_section **p,
 			 struct perf_evlist *evlist)
@@ -2440,6 +2471,7 @@ int perf_session__write_header(struct perf_session *session,
 			.size	= header->data_size,
 		},
 		/* event_types is ignored, store zeros */
+		/* first_sample_time and last_sample_time store 0 */
 	};
 
 	memcpy(&f_header.adds_features, &header->adds_features, sizeof(header->adds_features));
@@ -2627,6 +2659,8 @@ int perf_file_header__read(struct perf_file_header *header,
 			   struct perf_header *ph, int fd)
 {
 	ssize_t ret;
+	bool format_feature = true;
+	bool format_time = true;
 
 	lseek(fd, 0, SEEK_SET);
 
@@ -2647,11 +2681,22 @@ int perf_file_header__read(struct perf_file_header *header,
 
 	if (header->size != sizeof(*header)) {
 		/* Support the previous format */
-		if (header->size == offsetof(typeof(*header), adds_features))
+		if (header->size == offsetof(typeof(*header), adds_features)) {
 			bitmap_zero(header->adds_features, HEADER_FEAT_BITS);
-		else
+			header->first_sample_time = 0;
+			header->last_sample_time = 0;
+			format_feature = false;
+			format_time = false;
+		} else if (header->size == offsetof(typeof(*header),
+				first_sample_time)) {
+			header->first_sample_time = 0;
+			header->last_sample_time = 0;
+			format_time = false;
+		} else
 			return -1;
-	} else if (ph->needs_swap) {
+	}
+
+	if (ph->needs_swap && format_feature) {
 		/*
 		 * feature bitmap is declared as an array of unsigned longs --
 		 * not good since its size can differ between the host that
@@ -2686,6 +2731,11 @@ int perf_file_header__read(struct perf_file_header *header,
 		}
 	}
 
+	if (ph->needs_swap && format_time) {
+		header->first_sample_time = bswap_64(header->first_sample_time);
+		header->last_sample_time = bswap_64(header->last_sample_time);
+	}
+
 	memcpy(&ph->adds_features, &header->adds_features,
 	       sizeof(ph->adds_features));
 
@@ -2942,6 +2992,9 @@ int perf_session__read_header(struct perf_session *session)
 		lseek(fd, tmp, SEEK_SET);
 	}
 
+	session->first_sample_time = f_header.first_sample_time;
+	session->last_sample_time = f_header.last_sample_time;
+
 	symbol_conf.nr_events = nr_attrs;
 
 	perf_header__process_sections(header, fd, &session->tevent,
diff --git a/tools/perf/util/header.h b/tools/perf/util/header.h
index f7a16ee..cba51e8 100644
--- a/tools/perf/util/header.h
+++ b/tools/perf/util/header.h
@@ -56,6 +56,8 @@ struct perf_file_header {
 	/* event_types is ignored */
 	struct perf_file_section	event_types;
 	DECLARE_BITMAP(adds_features, HEADER_FEAT_BITS);
+	u64				first_sample_time;
+	u64				last_sample_time;
 };
 
 struct perf_pipe_file_header {
@@ -101,6 +103,8 @@ int perf_header__process_sections(struct perf_header *header, int fd,
 
 int perf_header__fprintf_info(struct perf_session *s, FILE *fp, bool full);
 
+int perf_header__update_sample_time(int fd, u64 first_time, u64 last_time);
+
 int perf_event__synthesize_features(struct perf_tool *tool,
 				    struct perf_session *session,
 				    struct perf_evlist *evlist,
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index 47b5e7d..f98a3ca 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -31,6 +31,8 @@ struct perf_session {
 	bool			one_mmap;
 	void			*one_mmap_addr;
 	u64			one_mmap_offset;
+	u64			first_sample_time;
+	u64			last_sample_time;
 	struct ordered_events	ordered_events;
 	struct perf_data_file	*file;
 	struct perf_tool	*tool;
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1736761 — Re: [PATCH v1 1/6] perf record: Record the first sample time and last sample time to perf file header

On Wed, Sep 20, 2017 at 11:12:32PM +0800, Jin Yao wrote:

SNIP

> @@ -2686,6 +2731,11 @@ int perf_file_header__read(struct perf_file_header *header,
>  		}
>  	}
>  
> +	if (ph->needs_swap && format_time) {
> +		header->first_sample_time = bswap_64(header->first_sample_time);
> +		header->last_sample_time = bswap_64(header->last_sample_time);
> +	}
> +
>  	memcpy(&ph->adds_features, &header->adds_features,
>  	       sizeof(ph->adds_features));
>  
> @@ -2942,6 +2992,9 @@ int perf_session__read_header(struct perf_session *session)
>  		lseek(fd, tmp, SEEK_SET);
>  	}
>  
> +	session->first_sample_time = f_header.first_sample_time;
> +	session->last_sample_time = f_header.last_sample_time;
> +
>  	symbol_conf.nr_events = nr_attrs;
>  
>  	perf_header__process_sections(header, fd, &session->tevent,
> diff --git a/tools/perf/util/header.h b/tools/perf/util/header.h
> index f7a16ee..cba51e8 100644
> --- a/tools/perf/util/header.h
> +++ b/tools/perf/util/header.h
> @@ -56,6 +56,8 @@ struct perf_file_header {
>  	/* event_types is ignored */
>  	struct perf_file_section	event_types;
>  	DECLARE_BITMAP(adds_features, HEADER_FEAT_BITS);
> +	u64				first_sample_time;
> +	u64				last_sample_time;

you can't add it here just like that, because you lose the
backward compatibility.. you need to add new feature

jirka

[toc] | [prev] | [next] | [standalone]

#1736763 — Re: [PATCH v1 1/6] perf record: Record the first sample time and last sample time to perf file header

On Wed, Sep 20, 2017 at 11:12:32PM +0800, Jin Yao wrote:

SNIP

> @@ -2647,11 +2681,22 @@ int perf_file_header__read(struct perf_file_header *header,
>  
>  	if (header->size != sizeof(*header)) {
>  		/* Support the previous format */
> -		if (header->size == offsetof(typeof(*header), adds_features))
> +		if (header->size == offsetof(typeof(*header), adds_features)) {
>  			bitmap_zero(header->adds_features, HEADER_FEAT_BITS);
> -		else
> +			header->first_sample_time = 0;
> +			header->last_sample_time = 0;
> +			format_feature = false;
> +			format_time = false;
> +		} else if (header->size == offsetof(typeof(*header),
> +				first_sample_time)) {
> +			header->first_sample_time = 0;
> +			header->last_sample_time = 0;
> +			format_time = false;
> +		} else

ok, disregard my previou comment.. I should have read the full patch first ;-)

jirka

[toc] | [prev] | [next] | [standalone]

#1736770 — Re: [PATCH v1 1/6] perf record: Record the first sample time and last sample time to perf file header

On Thu, Sep 21, 2017 at 05:18:42PM +0200, Jiri Olsa wrote:
> On Wed, Sep 20, 2017 at 11:12:32PM +0800, Jin Yao wrote:
> 
> SNIP
> 
> > @@ -2647,11 +2681,22 @@ int perf_file_header__read(struct perf_file_header *header,
> >  
> >  	if (header->size != sizeof(*header)) {
> >  		/* Support the previous format */
> > -		if (header->size == offsetof(typeof(*header), adds_features))
> > +		if (header->size == offsetof(typeof(*header), adds_features)) {
> >  			bitmap_zero(header->adds_features, HEADER_FEAT_BITS);
> > -		else
> > +			header->first_sample_time = 0;
> > +			header->last_sample_time = 0;
> > +			format_feature = false;
> > +			format_time = false;
> > +		} else if (header->size == offsetof(typeof(*header),
> > +				first_sample_time)) {
> > +			header->first_sample_time = 0;
> > +			header->last_sample_time = 0;
> > +			format_time = false;
> > +		} else
> 
> ok, disregard my previou comment.. I should have read the full patch first ;-)

still using the feature looks better to me.. I think we could
add some generic TLV data feature for cases like this

jirka

[toc] | [prev] | [next] | [standalone]

#1737115 — Re: [PATCH v1 1/6] perf record: Record the first sample time and last sample time to perf file header

On 9/21/2017 11:21 PM, Jiri Olsa wrote:
> On Thu, Sep 21, 2017 at 05:18:42PM +0200, Jiri Olsa wrote:
>> On Wed, Sep 20, 2017 at 11:12:32PM +0800, Jin Yao wrote:
>>
>> SNIP
>>
>>> @@ -2647,11 +2681,22 @@ int perf_file_header__read(struct perf_file_header *header,
>>>  
>>>  	if (header->size != sizeof(*header)) {
>>>  		/* Support the previous format */
>>> -		if (header->size == offsetof(typeof(*header), adds_features))
>>> +		if (header->size == offsetof(typeof(*header), adds_features)) {
>>>  			bitmap_zero(header->adds_features, HEADER_FEAT_BITS);
>>> -		else
>>> +			header->first_sample_time = 0;
>>> +			header->last_sample_time = 0;
>>> +			format_feature = false;
>>> +			format_time = false;
>>> +		} else if (header->size == offsetof(typeof(*header),
>>> +				first_sample_time)) {
>>> +			header->first_sample_time = 0;
>>> +			header->last_sample_time = 0;
>>> +			format_time = false;
>>> +		} else
>>
>> ok, disregard my previou comment.. I should have read the full patch first ;-)
> 
> still using the feature looks better to me.. I think we could
> add some generic TLV data feature for cases like this
> 
> jirka
> 

Thanks for the comments!

I will check how to add generic TLV data feature to record the first sample time and last sample time.

Thanks
Jin Yao

[toc] | [prev] | [next] | [standalone]

#1735591 — [PATCH v1 6/6] perf script: support time percent and multiple time ranges

perf 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%

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

diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index 18dfcfa..f772f37 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -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.
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 3d4c3b5..ddb9516 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1332,6 +1332,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;
@@ -1345,6 +1347,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)
@@ -1537,8 +1541,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) {
@@ -3074,8 +3081,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->first_sample_time,
+					session->last_sample_time);
+
+		if (script.range_num < 0) {
+			pr_err("Invalid time string\n");
+			return -EINVAL;
+		}
 	}
 
 	err = __cmd_script(&script);
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1735592 — [PATCH v1 2/6] perf Documentation: Update perf.data-file-format.txt

Currently the perf.data file starts with a perf_file_header,
while in the document, it's perf_header. So update it by the
new definition.

It also adds the description for new fields first_sample_time
and last_sample_time. The new fields will be used in perf
record/script/... to slice the traces.

Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
---
 tools/perf/Documentation/perf.data-file-format.txt | 27 +++++++++++++---------
 1 file changed, 16 insertions(+), 11 deletions(-)

diff --git a/tools/perf/Documentation/perf.data-file-format.txt b/tools/perf/Documentation/perf.data-file-format.txt
index e90c59c..7c27403 100644
--- a/tools/perf/Documentation/perf.data-file-format.txt
+++ b/tools/perf/Documentation/perf.data-file-format.txt
@@ -14,17 +14,18 @@ format that does not rely on seeking to adjust data offsets.  This
 format is described in "Pipe-mode data" section. The pipe data version can be
 augmented with additional events using perf inject.
 
-The file starts with a perf_header:
-
-struct perf_header {
-	char magic[8];		/* PERFILE2 */
-	uint64_t size;		/* size of the header */
-	uint64_t attr_size;	/* size of an attribute in attrs */
-	struct perf_file_section attrs;
-	struct perf_file_section data;
-	struct perf_file_section event_types;
-	uint64_t flags;
-	uint64_t flags1[3];
+The file starts with a perf_file_header:
+
+struct perf_file_header {
+	u64				magic;
+	u64				size;
+	u64				attr_size;
+	struct perf_file_section	attrs;
+	struct perf_file_section	data;
+	struct perf_file_section	event_types;
+	DECLARE_BITMAP(adds_features, HEADER_FEAT_BITS);
+	u64				first_sample_time;
+	u64				last_sample_time;
 };
 
 The magic number identifies the perf file and the version. Current perf versions
@@ -416,6 +417,10 @@ An array bound by the perf_file_section size.
 
 ids points to a array of uint64_t defining the ids for event attr attr.
 
+first_sample_time and last_sample_time record the timestmaps of first sample
+and last sample. In later, perf record will fetch the time from perf file
+header and use them to slice the traces for parallelization.
+
 Pipe-mode data
 
 Pipe-mode avoid seeks in the file by removing the perf_file_section and flags
-- 
2.7.4

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web