Add --show-total-period for perf annotate

RFC In review Martin Liška 2 participants 12 messages May 22, 2015 – Jun 1, 2015 perf events

lore

Share & tools

lore

Martin Liška

author

2015-05-22 14:39 UTC #0 lore raw

RFC 1/1 Add --show-total-period for perf annotate

Hello.

I've been working on a new feature for perf annotate, which should be able to annotate instructions with total spent time (compared to percentage usage).

Let's consider following use-case. You want to compare two different compilers on the same code base and let's assume 90% of wall-time is spent in a single function. Moreover, let's say that these compilers produce assembly of a totally different size.

In such case, it's very useful to get an approximation of spent time on a bunch of instructions, which can be compared among other compilers. Otherwise, one has to somehow sum percentages and compare it to size of a function.

Mail contains my experimental patch.

However, last missing thing is that I need to calculate portion of cycles a function utilizes. May I ask you for help as perf annotate does not count these portions.

Thanks,
Martin

tools/perf/builtin-annotate.c +2 -0

index b57a027..cce19d6 100644
@@ -326,6 +326,8 @@ int cmd_annotate(int argc, const char **argv, const char *prefix __maybe_unused)
 		   "objdump binary to use for disassembly and annotations"),
 	OPT_BOOLEAN(0, "group", &symbol_conf.event_group,
 		    "Show event group information together"),
+	OPT_BOOLEAN(0, "show-total-period", &symbol_conf.show_total_period,
+		    "Show a column with the sum of periods"),
 	OPT_END()
 	};
 	int ret = hists__init();

tools/perf/builtin-record.c +6 -0

index 5dfe913..dfd0c8c 100644
@@ -484,6 +484,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	struct perf_session *session;
 	bool disabled = false, draining = false;
 	int fd;
+	unsigned long long t0, t1;
 
 	rec->progname = argv[0];

@@ -623,6 +624,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	if (!target__none(&opts->target) && !opts->initial_delay)
 		perf_evlist__enable(rec->evlist);
 
+	t0 = rdclock();
+
 	/*
 	 * Let the child rip
 	 */

@@ -692,6 +695,9 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		goto out_child;
 	}
 
+	t1 = rdclock();
+	walltime_nsecs = t1 - t0;
+
 	if (!quiet)
 		fprintf(stderr, "[ perf record: Woken up %ld times to write data ]\n", waking);

tools/perf/perf.h +2 -0

index aa79fb8..0acdf4c 100644
@@ -35,6 +35,8 @@ extern const char *input_name;
 extern bool perf_host, perf_guest;
 extern const char perf_version_string[];
 
+extern unsigned long long walltime_nsecs;
+
 void pthread__unblock_sigwinch(void);
 
 #include "util/target.h"

tools/perf/ui/browsers/annotate.c +6 -1

index e5250eb..e7af8ec 100644
@@ -113,7 +113,12 @@ static void annotate_browser__write(struct ui_browser *browser, void *entry, int
 		for (i = 0; i < ab->nr_events; i++) {
 			ui_browser__set_percent_color(browser, bdl->percent[i],
 						      current_entry);
-			slsmg_printf("%6.2f ", bdl->percent[i]);
+
+			if (symbol_conf.show_total_period)
+			  slsmg_printf("%7.0f ", bdl->percent[i] *
+				       walltime_nsecs / (100 * 1e6));
+			else
+			  slsmg_printf("%7.2f ", bdl->percent[i]);
 		}
 	} else {
 		ui_browser__set_percent_color(browser, 0, current_entry);

tools/perf/util/annotate.c +6 -1

index 7f5bdfc..263e1bf 100644
@@ -753,7 +753,12 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		for (i = 0; i < nr_percent; i++) {
 			percent = ppercents[i];
 			color = get_percent_color(percent);
-			color_fprintf(stdout, color, " %7.2f", percent);
+
+			if (symbol_conf.show_total_period)
+			  color_fprintf(stdout, color, " %7.0f",
+					percent * walltime_nsecs / (100 * 1e6));
+			else
+			  color_fprintf(stdout, color, " %7.2f", percent);
 		}
 
 		printf(" :	");

tools/perf/util/header.c +35 -0

index 3f0d809..a1d254b 100644
@@ -47,6 +47,8 @@ struct perf_file_attr {
 	struct perf_file_section	ids;
 };
 
+unsigned long long walltime_nsecs;
+
 void perf_header__set_feat(struct perf_header *header, int feat)
 {
 	set_bit(feat, header->adds_features);

@@ -883,6 +885,14 @@ static int write_auxtrace(int fd, struct perf_header *h,
 	return err;
 }
 
+static int write_total_wall_time(int fd, struct perf_header *h __maybe_unused,
+			   struct perf_evlist *evlist __maybe_unused)
+{
+	do_write (fd, &walltime_nsecs, sizeof (walltime_nsecs));
+	return 0;
+}
+
+
 static void print_hostname(struct perf_header *ph, int fd __maybe_unused,
 			   FILE *fp)
 {

@@ -1171,6 +1181,13 @@ static void print_auxtrace(struct perf_header *ph __maybe_unused,
 	fprintf(fp, "# contains AUX area data (e.g. instruction trace)\n");
 }
 
+static void print_total_wall_time(struct perf_header *ph, int fd __maybe_unused,
+			    FILE *fp)
+{
+	fprintf(fp, "# total wall-time: %.9f second\n",
+		ph->env.total_wall_time / 1e9);
+}
+
 static void print_pmu_mappings(struct perf_header *ph, int fd __maybe_unused,
 			       FILE *fp)
 {

@@ -1857,6 +1874,23 @@ static int process_auxtrace(struct perf_file_section *section,
 	return err;
 }
 
+static int process_total_wall_time(struct perf_file_section *section __maybe_unused,
+			     struct perf_header *ph, int fd,
+			     void *data __maybe_unused)
+{
+	ssize_t ret;
+
+	ret = readn(fd, &walltime_nsecs, sizeof(walltime_nsecs));
+	if (ret != sizeof(walltime_nsecs))
+		return -1;
+
+	if (ph->needs_swap)
+		walltime_nsecs = bswap_64(walltime_nsecs);
+
+	ph->env.total_wall_time = walltime_nsecs;
+	return 0;
+}
+
 struct feature_ops {
 	int (*write)(int fd, struct perf_header *h, struct perf_evlist *evlist);
 	void (*print)(struct perf_header *h, int fd, FILE *fp);

@@ -1898,6 +1932,7 @@ static const struct feature_ops feat_ops[HEADER_LAST_FEATURE] = {
 	FEAT_OPP(HEADER_PMU_MAPPINGS,	pmu_mappings),
 	FEAT_OPP(HEADER_GROUP_DESC,	group_desc),
 	FEAT_OPP(HEADER_AUXTRACE,	auxtrace),
+	FEAT_OPP(HEADER_TOTAL_WALLTIME,	total_wall_time),
 };
 
 struct header_print_data {

tools/perf/util/header.h +2 -0

index d4d5796..f47571a 100644
@@ -31,6 +31,7 @@ enum {
 	HEADER_PMU_MAPPINGS,
 	HEADER_GROUP_DESC,
 	HEADER_AUXTRACE,
+	HEADER_TOTAL_WALLTIME,
 	HEADER_LAST_FEATURE,
 	HEADER_FEAT_BITS	= 256,
 };

@@ -88,6 +89,7 @@ struct perf_session_env {
 	char			*sibling_threads;
 	char			*numa_nodes;
 	char			*pmu_mappings;
+	unsigned long long	total_wall_time;
 };
 
 struct perf_header {

Signature · 1 line

2.1.4

Andi Kleen

2015-05-23 04:08 UTC #1 lore raw

Quoted 10 lines · Martin Liška

I've been working on a new feature for perf annotate, which should be able to annotate instructions with total spent time (compared to percentage usage).
Let's consider following use-case. You want to compare two different compilers on the same code base and let's assume 90% of wall-time is spent in a single function. Moreover, let's say that these compilers produce assembly of a totally different size.
In such case, it's very useful to get an approximation of spent time on a bunch of instructions, which can be compared among other compilers. Otherwise, one has to somehow sum percentages and compare it to size of a function.

perf diff does not handle this? Especially with the differential profiling options it should.

Quoted 10 lines

Quoted 1 line

(quoted diff) +0 -0

@@ -623,6 +624,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)

tools/perf/builtin-record.c +2 -0

 	if (!target__none(&opts->target) && !opts->initial_delay)
 		perf_evlist__enable(rec->evlist);
 
+	t0 = rdclock();
+
 	/*
 	 * Let the child rip
 	 */

tools/perf/builtin-record.c static int __cmd_record(struct record *rec, int argc, const char **argv) · line 699

Quoted 5 lines

tools/perf/builtin-record.c +2 -0

@@ -692,6 +695,9 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		goto out_child;
 	}
 
+	t1 = rdclock();
+	walltime_nsecs = t1 - t0;

The walltime can be later computed by the difference of the first and the last time stamp after sorting the events. So you don't need the new header.

-Andi

Signature · 1 line

[email protected] -- Speaking for myself only

Martin Liška

author

2015-05-25 07:46 UTC #2 lore raw

Quoted 9 lines · Andi Kleen

Quoted 7 lines · Martin Liška
I've been working on a new feature for perf annotate, which should be able to annotate instructions with total spent time (compared to percentage usage).
Let's consider following use-case. You want to compare two different compilers on the same code base and let's assume 90% of wall-time is spent in a single function. Moreover, let's say that these compilers produce assembly of a totally different size.

Quoted 6 lines

Quoted 3 lines
In such case, it's very useful to get an approximation of spent time on a bunch of instructions, which can be compared among other compilers. Otherwise, one has to somehow sum percentages and compare it to size of a function.
perf diff does not handle this? Especially with the differential profiling options it should.

It does not work if you, in my case, compare ICC and GCC, where ICC uses a different mangling scheme for fortran modules. Moreover, situation can be more complicated if a compiler performs a bit different inlining decisions.

Quoted 14 lines

Quoted 14 lines
Review static int __cmd_record(struct record *rec, int argc, const char **argv)
Quoted 2 lines
(quoted diff) +0 -0
@@ -623,6 +624,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
if (!target__none(&opts->target) && !opts->initial_delay)
perf_evlist__enable(rec->evlist);
tools/perf/builtin-record.c +2 -0
+	t0 = rdclock();
+
  	/*
  	 * Let the child rip
  	 */
@@ -692,6 +695,9 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
  		goto out_child;
  	}
 

Quoted 8 lines

tools/perf/builtin-record.c static int __cmd_record(struct record *rec, int argc, const char **argv) · line 699
Quoted 2 lines
tools/perf/builtin-record.c +2 -0
+	t1 = rdclock();
+	walltime_nsecs = t1 - t0;
The walltime can be later computed by the difference of the first and the last time stamp after sorting the events. So you don't need the new header.
-Andi

Good point. Can you please help me how to compute a function percentage usage in perf annotate ;) ?

Thanks,
Martin

Andi Kleen

2015-05-25 15:14 UTC #3 lore raw

Quoted 6 lines

Quoted 2 lines
perf diff does not handle this? Especially with the differential profiling options it should.
It does not work if you, in my case, compare ICC and GCC, where ICC uses a different mangling scheme for fortran modules. Moreover, situation can be more complicated if a compiler performs a bit different inlining decisions.

I suppose it could be enhanced with an input file that describes equivalent functions. But yes wouldn't work for inlining.

Quoted 1 line

Good point. Can you please help me how to compute a function percentage usage in perf annotate ;) ?

I wouldn't use time at all. Just sum up periods and then compute the percentage. The period sum computation already happens in the main view, and is displayed there. So you only need to save that value somewhere and then use it in the annotate display for another column.

# Samples: 24 of event 'cycles'
# Event count (approx.): 8856637

-Andi

Signature · 1 line

[email protected] -- Speaking for myself only.

Martin Liška

author

2015-05-26 13:13 UTC #4 lore raw

Quoted 17 lines · Andi Kleen

Quoted 6 lines
Quoted 2 lines
perf diff does not handle this? Especially with the differential profiling options it should.
It does not work if you, in my case, compare ICC and GCC, where ICC uses a different mangling scheme for fortran modules. Moreover, situation can be more complicated if a compiler performs a bit different inlining decisions.
I suppose it could be enhanced with an input file that describes equivalent functions. But yes wouldn't work for inlining.
Quoted 1 line
Good point. Can you please help me how to compute a function percentage usage in perf annotate ;) ?
I wouldn't use time at all. Just sum up periods and then compute the percentage. The period sum computation already happens in the main view, and is displayed there. So you only need to save that value somewhere and then use it in the annotate display for another column.

Quoted 5 lines

# Samples: 24 of event 'cycles'
# Event count (approx.): 8856637
-Andi

Hello.

Are you talking about summing cycles and compute global percentage for each isntruction?

Anyway, attached patch is capable of displaying milliseconds approximation for each instruction.

Example:

time ./perf record ./a.out
[ perf record: Woken up 7 times to write data ]
[ perf record: Captured and wrote 1.743 MB perf.data (45386 samples) ]

real 0m11.465s
user 0m11.424s
sys 0m0.045s

$ perf report --stdio

    32.69%  a.out    libc-2.19.so       [.] __random_r
    26.66%  a.out    libc-2.19.so       [.] __random
    12.55%  a.out    a.out              [.] foo
    10.14%  a.out    a.out              [.] bar
     9.27%  a.out    a.out              [.] baz
     7.22%  a.out    libc-2.19.so       [.] rand
     1.37%  a.out    a.out              [.] rand@plt

$ perf annotate --stdio

Percent | Source code & Disassembly of libc-2.19.so for cycles
--------------------------------------------------------------------

         :
         :
         :
         :      Disassembly of section .text:
         :
         :      0000000000038890 <random_r>:
         :      __random_r():

11.12 : 38890: test %rdi,%rdi

$ perf annotate --stdio --show-total-period
 Percent |      Source code & Disassembly of libc-2.19.so for cycles
--------------------------------------------------------------------
         :
         :
         :
         :      Disassembly of section .text:
         :
         :      0000000000038890 <random_r>:
         :      __random_r():
     413 :        38890:       test   %rdi,%rdi

First test instruction: 11465*0.3269*0.1112 ~ 413ms.

Thanks for suggestions,
Martin

tools/perf/builtin-annotate.c +2 -0

index b57a027..cce19d6 100644
@@ -326,6 +326,8 @@ int cmd_annotate(int argc, const char **argv, const char *prefix __maybe_unused)
 		   "objdump binary to use for disassembly and annotations"),
 	OPT_BOOLEAN(0, "group", &symbol_conf.event_group,
 		    "Show event group information together"),
+	OPT_BOOLEAN(0, "show-total-period", &symbol_conf.show_total_period,
+		    "Show a column with the sum of periods"),
 	OPT_END()
 	};
 	int ret = hists__init();

tools/perf/builtin-record.c +6 -0

index 5dfe913..dfd0c8c 100644
@@ -484,6 +484,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	struct perf_session *session;
 	bool disabled = false, draining = false;
 	int fd;
+	unsigned long long t0, t1;
 
 	rec->progname = argv[0];

@@ -623,6 +624,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	if (!target__none(&opts->target) && !opts->initial_delay)
 		perf_evlist__enable(rec->evlist);
 
+	t0 = rdclock();
+
 	/*
 	 * Let the child rip
 	 */

@@ -692,6 +695,9 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		goto out_child;
 	}
 
+	t1 = rdclock();
+	walltime_nsecs = t1 - t0;
+
 	if (!quiet)
 		fprintf(stderr, "[ perf record: Woken up %ld times to write data ]\n", waking);

tools/perf/perf.h +2 -0

index aa79fb8..0acdf4c 100644
@@ -35,6 +35,8 @@ extern const char *input_name;
 extern bool perf_host, perf_guest;
 extern const char perf_version_string[];
 
+extern unsigned long long walltime_nsecs;
+
 void pthread__unblock_sigwinch(void);
 
 #include "util/target.h"

tools/perf/ui/browsers/annotate.c +6 -1

index e5250eb..e7af8ec 100644
@@ -113,7 +113,12 @@ static void annotate_browser__write(struct ui_browser *browser, void *entry, int
 		for (i = 0; i < ab->nr_events; i++) {
 			ui_browser__set_percent_color(browser, bdl->percent[i],
 						      current_entry);
-			slsmg_printf("%6.2f ", bdl->percent[i]);
+
+			if (symbol_conf.show_total_period)
+			  slsmg_printf("%7.0f ", bdl->percent[i] *
+				       walltime_nsecs / (100 * 1e6));
+			else
+			  slsmg_printf("%7.2f ", bdl->percent[i]);
 		}
 	} else {
 		ui_browser__set_percent_color(browser, 0, current_entry);

tools/perf/util/annotate.c +6 -1

index 7f5bdfc..263e1bf 100644
@@ -753,7 +753,12 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		for (i = 0; i < nr_percent; i++) {
 			percent = ppercents[i];
 			color = get_percent_color(percent);
-			color_fprintf(stdout, color, " %7.2f", percent);
+
+			if (symbol_conf.show_total_period)
+			  color_fprintf(stdout, color, " %7.0f",
+					percent * walltime_nsecs / (100 * 1e6));
+			else
+			  color_fprintf(stdout, color, " %7.2f", percent);
 		}
 
 		printf(" :	");

tools/perf/util/header.c +35 -0

index 3f0d809..a1d254b 100644
@@ -47,6 +47,8 @@ struct perf_file_attr {
 	struct perf_file_section	ids;
 };
 
+unsigned long long walltime_nsecs;
+
 void perf_header__set_feat(struct perf_header *header, int feat)
 {
 	set_bit(feat, header->adds_features);

@@ -883,6 +885,14 @@ static int write_auxtrace(int fd, struct perf_header *h,
 	return err;
 }
 
+static int write_total_wall_time(int fd, struct perf_header *h __maybe_unused,
+			   struct perf_evlist *evlist __maybe_unused)
+{
+	do_write (fd, &walltime_nsecs, sizeof (walltime_nsecs));
+	return 0;
+}
+
+
 static void print_hostname(struct perf_header *ph, int fd __maybe_unused,
 			   FILE *fp)
 {

@@ -1171,6 +1181,13 @@ static void print_auxtrace(struct perf_header *ph __maybe_unused,
 	fprintf(fp, "# contains AUX area data (e.g. instruction trace)\n");
 }
 
+static void print_total_wall_time(struct perf_header *ph, int fd __maybe_unused,
+			    FILE *fp)
+{
+	fprintf(fp, "# total wall-time: %.9f second\n",
+		ph->env.total_wall_time / 1e9);
+}
+
 static void print_pmu_mappings(struct perf_header *ph, int fd __maybe_unused,
 			       FILE *fp)
 {

@@ -1857,6 +1874,23 @@ static int process_auxtrace(struct perf_file_section *section,
 	return err;
 }
 
+static int process_total_wall_time(struct perf_file_section *section __maybe_unused,
+			     struct perf_header *ph, int fd,
+			     void *data __maybe_unused)
+{
+	ssize_t ret;
+
+	ret = readn(fd, &walltime_nsecs, sizeof(walltime_nsecs));
+	if (ret != sizeof(walltime_nsecs))
+		return -1;
+
+	if (ph->needs_swap)
+		walltime_nsecs = bswap_64(walltime_nsecs);
+
+	ph->env.total_wall_time = walltime_nsecs;
+	return 0;
+}
+
 struct feature_ops {
 	int (*write)(int fd, struct perf_header *h, struct perf_evlist *evlist);
 	void (*print)(struct perf_header *h, int fd, FILE *fp);

@@ -1898,6 +1932,7 @@ static const struct feature_ops feat_ops[HEADER_LAST_FEATURE] = {
 	FEAT_OPP(HEADER_PMU_MAPPINGS,	pmu_mappings),
 	FEAT_OPP(HEADER_GROUP_DESC,	group_desc),
 	FEAT_OPP(HEADER_AUXTRACE,	auxtrace),
+	FEAT_OPP(HEADER_TOTAL_WALLTIME,	total_wall_time),
 };
 
 struct header_print_data {

tools/perf/util/header.h +2 -0

index d4d5796..f47571a 100644
@@ -31,6 +31,7 @@ enum {
 	HEADER_PMU_MAPPINGS,
 	HEADER_GROUP_DESC,
 	HEADER_AUXTRACE,
+	HEADER_TOTAL_WALLTIME,
 	HEADER_LAST_FEATURE,
 	HEADER_FEAT_BITS	= 256,
 };

@@ -88,6 +89,7 @@ struct perf_session_env {
 	char			*sibling_threads;
 	char			*numa_nodes;
 	char			*pmu_mappings;
+	unsigned long long	total_wall_time;
 };
 
 struct perf_header {

Signature · 1 line

2.1.4

Andi Kleen

2015-05-26 17:03 UTC #5 lore raw

Quoted 1 line

Anyway, attached patch is capable of displaying milliseconds approximation for each instruction.

You realize that the events perf is not counting do not directly map to wall time? Even if you count cycles, the cycles are either stopping in idle or changing unit as the CPU's frequencies change. For other events the relationship is even more remote, think what happens when counting cache or TLB misses.

Also even if it was mapping to time somehow, it's just a hit, not a duration, so it cannot say how long a individual instruction took.

So you cannot map a sample event to time.

To do what you want you would need to use something like processor trace, which can do exact accounting.

I think the only thing that makes sense is to account it relative to the event counts.

-Andi

Martin Liška

author

2015-05-27 08:46 UTC #6 lore raw

Quoted 13 lines · Andi Kleen

Quoted 1 line
Anyway, attached patch is capable of displaying milliseconds approximation for each instruction.
You realize that the events perf is not counting do not directly map to wall time? Even if you count cycles, the cycles are either stopping in idle or changing unit as the CPU's frequencies change. For other events the relationship is even more remote, think what happens when counting cache or TLB misses.
Also even if it was mapping to time somehow, it's just a hit, not a duration, so it cannot say how long a individual instruction took.
So you cannot map a sample event to time.

Quoted 8 lines

To do what you want you would need to use something like processor trace, which can do exact accounting.
I think the only thing that makes sense is to account it relative to the event counts.
-Andi

Hello Andi.

I realize all aspects and capabilities of perf infrastructure. Even though these numbers are not precise, I helped me a lot with debugging of a benchmark which heavily utilizes a single CPU and runs in magnitude of seconds.

Ok, so let's convert the patch to feature that we can map an instruction to a percentage number of events (cycles) it takes.

If I understand correctly, is it just about division of the number of events related to an instruction and total number of events?

Thanks,
Martin

Martin Liška

author

2015-05-27 09:04 UTC #7 lore raw

Quoted 35 lines · Martin Liška

Quoted 13 lines · Andi Kleen
Quoted 1 line
Anyway, attached patch is capable of displaying milliseconds approximation for each instruction.
You realize that the events perf is not counting do not directly map to wall time? Even if you count cycles, the cycles are either stopping in idle or changing unit as the CPU's frequencies change. For other events the relationship is even more remote, think what happens when counting cache or TLB misses.
Also even if it was mapping to time somehow, it's just a hit, not a duration, so it cannot say how long a individual instruction took.
So you cannot map a sample event to time.
Quoted 8 lines
To do what you want you would need to use something like processor trace, which can do exact accounting.
I think the only thing that makes sense is to account it relative to the event counts.
-Andi
Hello Andi.
I realize all aspects and capabilities of perf infrastructure. Even though these numbers are not precise, I helped me a lot with debugging of a benchmark which heavily utilizes a single CPU and runs in magnitude of seconds.
Ok, so let's convert the patch to feature that we can map an instruction to a percentage number of events (cycles) it takes.
If I understand correctly, is it just about division of the number of events related to an instruction and total number of events?

Quoted 7 lines

Thanks,
Martin
--
To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hi.

Sample output to verify that we have the same idea in mind:

$ perf annotate --show-total-period

Disassembly of section .text:

         :
         :      0000000000038890 <random_r>:
         :      __random_r():
    1695 :        38890:       test   %rdi,%rdi
       0 :        38893:       je     38918 <random_r+0x88>
       1 :        38899:       test   %rsi,%rsi
       0 :        3889c:       je     38918 <random_r+0x88>
       9 :        3889e:       mov    0x18(%rdi),%eax
    1833 :        388a1:       mov    0x10(%rdi),%rdx
       2 :        388a5:       test   %eax,%eax
       0 :        388a7:       je     388f8 <random_r+0x68>
     168 :        388a9:       mov    (%rdi),%rcx
       8 :        388ac:       mov    0x8(%rdi),%r8
    1325 :        388b0:       mov    0x28(%rdi),%r9

Where:

$ perf report | head

# To display the perf.data header info, please use --header/--header-only options. #
# Samples: 44K of event 'cycles'
# Event count (approx.): 42988831618

Thank for ideas,
Martin

Andi Kleen

2015-05-27 14:04 UTC #8 lore raw

In reply to Martin Liška

Quoted 2 lines

If I understand correctly, is it just about division of the number of events related to an instruction and total number of events?

Yes that's it. The information is already displayed in the main view (or more fine grained if you do --sort ...,srcline; unfortunately not sorted in this case)

-Andi

Martin Liška

author

2015-05-29 12:58 UTC #9 lore raw

Quoted 8 lines · Andi Kleen

Quoted 2 lines
If I understand correctly, is it just about division of the number of events related to an instruction and total number of events?
Yes that's it. The information is already displayed in the main view (or more fine grained if you do --sort ...,srcline; unfortunately not sorted in this case)
-Andi

Hi.

Following patch sums samples that belong to a line in assembly language. What do you think about it, would it be acceptable solution?

Thanks,
Martin

Quoted 4 lines

--
To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

From 0435d25155315f30f2040d5adff3b5f2ca825089 Mon Sep 17 00:00:00 2001
From: mliska <[email protected]>
Date: Wed, 27 May 2015 10:54:42 +0200
Subject: [PATCH] perf annotate: With --show-total-period, display total # of
samples.

To compare two records on an instruction base, with --show-total-period option provided, display total number of samples that belong to a line in assembly language.

Signed-off-by Martin Liska <[email protected]>

---
 tools/perf/builtin-annotate.c     |  5 ++++-
 tools/perf/perf.h                 |  2 ++
 tools/perf/ui/browsers/annotate.c | 42 ++++++++++++++++++++++++---------------
 tools/perf/util/annotate.c        | 28 ++++++++++++++++++++------
 tools/perf/util/annotate.h        |  3 ++-
 5 files changed, 56 insertions(+), 24 deletions(-)

tools/perf/builtin-annotate.c +4 -1

index b57a027..38fc304 100644
@@ -46,6 +46,8 @@ struct perf_annotate {
 	DECLARE_BITMAP(cpu_bitmap, MAX_NR_CPUS);
 };
 
+unsigned long long total_nr_samples;
+
 static int perf_evsel__add_sample(struct perf_evsel *evsel,
 				  struct perf_sample *sample __maybe_unused,
 				  struct addr_location *al,

@@ -193,7 +195,6 @@ static int __cmd_annotate(struct perf_annotate *ann)
 	int ret;
 	struct perf_session *session = ann->session;
 	struct perf_evsel *pos;
-	u64 total_nr_samples;
 
 	machines__set_symbol_filter(&session->machines, symbol__annotate_init);

@@ -326,6 +327,8 @@ int cmd_annotate(int argc, const char **argv, const char *prefix __maybe_unused)
 		   "objdump binary to use for disassembly and annotations"),
 	OPT_BOOLEAN(0, "group", &symbol_conf.event_group,
 		    "Show event group information together"),
+	OPT_BOOLEAN(0, "show-total-period", &symbol_conf.show_total_period,
+		    "Show a column with the sum of periods"),
 	OPT_END()
 	};
 	int ret = hists__init();

tools/perf/perf.h +2 -0

index aa79fb8..9b629fc 100644
@@ -35,6 +35,8 @@ extern const char *input_name;
 extern bool perf_host, perf_guest;
 extern const char perf_version_string[];
 
+extern unsigned long long total_nr_samples;
+
 void pthread__unblock_sigwinch(void);
 
 #include "util/target.h"

tools/perf/ui/browsers/annotate.c +26 ~~-16~~

87 lines not on this page · raw message

tools/perf/util/annotate.c +22 -6

index 7f5bdfc..797ce62 100644
@@ -647,10 +647,11 @@ struct disasm_line *disasm__get_next_ip_line(struct list_head *head, struct disa
 }
 
 double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
-			    s64 end, const char **path)
+			    s64 end, const char **path, double *samples)
 {
 	struct source_line *src_line = notes->src->lines;
 	double percent = 0.0;
+	*samples = 0.0;
 
 	if (src_line) {
 		size_t sizeof_src_line = sizeof(*src_line) +

@@ -664,6 +665,7 @@ double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
 				*path = src_line->path;
 
 			percent += src_line->p[evidx].percent;
+			*samples += src_line->p[evidx].samples;
 			offset++;
 		}
 	} else {

@@ -673,8 +675,10 @@ double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
 		while (offset < end)
 			hits += h->addr[offset++];
 
-		if (h->sum)
+		if (h->sum) {
+			*samples = hits;
 			percent = 100.0 * hits / h->sum;
+		}
 	}
 
 	return percent;

@@ -689,8 +693,9 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 
 	if (dl->offset != -1) {
 		const char *path = NULL;
-		double percent, max_percent = 0.0;
+		double percent, samples, max_percent = 0.0;
 		double *ppercents = &percent;
+		double *psamples= &samples;
 		int i, nr_percent = 1;
 		const char *color;
 		struct annotation *notes = symbol__annotation(sym);

@@ -703,8 +708,10 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		if (perf_evsel__is_group_event(evsel)) {
 			nr_percent = evsel->nr_members;
 			ppercents = calloc(nr_percent, sizeof(double));
-			if (ppercents == NULL)
+			psamples= calloc(nr_percent, sizeof(double));
+			if (ppercents == NULL || psamples == NULL) {
 				return -1;
+			}
 		}
 
 		for (i = 0; i < nr_percent; i++) {

@@ -712,9 +719,10 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 					notes->src->lines ? i : evsel->idx + i,
 					offset,
 					next ? next->offset : (s64) len,
-					&path);
+					&path, &samples);
 
 			ppercents[i] = percent;
+			psamples[i] = samples;
 			if (percent > max_percent)
 				max_percent = percent;
 		}

@@ -752,8 +760,13 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 
 		for (i = 0; i < nr_percent; i++) {
 			percent = ppercents[i];
+			samples = psamples[i];
 			color = get_percent_color(percent);
-			color_fprintf(stdout, color, " %7.2f", percent);
+
+			if (symbol_conf.show_total_period)
+				color_fprintf(stdout, color, " %7.0f", samples);
+			else
+				color_fprintf(stdout, color, " %7.2f", percent);
 		}
 
 		printf(" :	");

@@ -763,6 +776,9 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		if (ppercents != &percent)
 			free(ppercents);
 
+		if (psamples != &samples)
+			free(psamples);
+
 	} else if (max_lines && printed >= max_lines)
 		return 1;
 	else {

tools/perf/util/annotate.h +2 -1

index cadbdc9..b3ffb87 100644
@@ -72,7 +72,7 @@ struct disasm_line *disasm__get_next_ip_line(struct list_head *head, struct disa
 int disasm_line__scnprintf(struct disasm_line *dl, char *bf, size_t size, bool raw);
 size_t disasm__fprintf(struct list_head *head, FILE *fp);
 double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
-			    s64 end, const char **path);
+			    s64 end, const char **path, double *samples);
 
 struct sym_hist {
 	u64		sum;

@@ -81,6 +81,7 @@ struct sym_hist {
 
 struct source_line_percent {
 	double		percent;
+	double          samples;
 	double		percent_sum;
 };

Signature · 1 line

2.1.4

Andi Kleen

2015-05-29 15:55 UTC #10 lore raw

Quoted 3 lines · Martin Liška

Following patch sums samples that belong to a line in assembly language. What do you think about it, would it be acceptable solution?

Basic patch looks good to me now. Thanks.

The only ugly thing is the global variable, perhaps that could be cleaned up.

-Andi

Signature · 1 line

[email protected] -- Speaking for myself only

Martin Liška

author

2015-06-01 11:08 UTC #11 lore raw

Quoted 5 lines · Andi Kleen

Quoted 3 lines · Martin Liška
Following patch sums samples that belong to a line in assembly language. What do you think about it, would it be acceptable solution?

Quoted 7 lines

Basic patch looks good to me now. Thanks.
The only ugly thing is the global variable, perhaps that could be cleaned up.
-Andi

Hello.

You are right, the global variable is not needed anymore as we do not count any fraction related to samples related to a line in assembly language.

Please look at attached patch.

Thank you,
Martin

From 285596ea221e1b6bb2fb8cb06ade6ae5f04a09a0 Mon Sep 17 00:00:00 2001
From: mliska <[email protected]>
Date: Wed, 27 May 2015 10:54:42 +0200
Subject: [PATCH] perf annotate: With --show-total-period, display total # of
samples.

To compare two records on an instruction base, with --show-total-period option provided, display total number of samples that belong to a line in assembly language.

Signed-off-by Martin Liska <[email protected]>

---
 tools/perf/builtin-annotate.c     |  2 ++
 tools/perf/ui/browsers/annotate.c | 42 ++++++++++++++++++++++++---------------
 tools/perf/util/annotate.c        | 28 ++++++++++++++++++++------
 tools/perf/util/annotate.h        |  3 ++-
 4 files changed, 52 insertions(+), 23 deletions(-)

tools/perf/builtin-annotate.c +2 -0

index b57a027..cce19d6 100644
@@ -326,6 +326,8 @@ int cmd_annotate(int argc, const char **argv, const char *prefix __maybe_unused)
 		   "objdump binary to use for disassembly and annotations"),
 	OPT_BOOLEAN(0, "group", &symbol_conf.event_group,
 		    "Show event group information together"),
+	OPT_BOOLEAN(0, "show-total-period", &symbol_conf.show_total_period,
+		    "Show a column with the sum of periods"),
 	OPT_END()
 	};
 	int ret = hists__init();

tools/perf/ui/browsers/annotate.c +26 ~~-16~~

87 lines not on this page · raw message

tools/perf/util/annotate.c +22 -6

index 7f5bdfc..797ce62 100644
@@ -647,10 +647,11 @@ struct disasm_line *disasm__get_next_ip_line(struct list_head *head, struct disa
 }
 
 double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
-			    s64 end, const char **path)
+			    s64 end, const char **path, double *samples)
 {
 	struct source_line *src_line = notes->src->lines;
 	double percent = 0.0;
+	*samples = 0.0;
 
 	if (src_line) {
 		size_t sizeof_src_line = sizeof(*src_line) +

@@ -664,6 +665,7 @@ double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
 				*path = src_line->path;
 
 			percent += src_line->p[evidx].percent;
+			*samples += src_line->p[evidx].samples;
 			offset++;
 		}
 	} else {

@@ -673,8 +675,10 @@ double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
 		while (offset < end)
 			hits += h->addr[offset++];
 
-		if (h->sum)
+		if (h->sum) {
+			*samples = hits;
 			percent = 100.0 * hits / h->sum;
+		}
 	}
 
 	return percent;

@@ -689,8 +693,9 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 
 	if (dl->offset != -1) {
 		const char *path = NULL;
-		double percent, max_percent = 0.0;
+		double percent, samples, max_percent = 0.0;
 		double *ppercents = &percent;
+		double *psamples= &samples;
 		int i, nr_percent = 1;
 		const char *color;
 		struct annotation *notes = symbol__annotation(sym);

@@ -703,8 +708,10 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		if (perf_evsel__is_group_event(evsel)) {
 			nr_percent = evsel->nr_members;
 			ppercents = calloc(nr_percent, sizeof(double));
-			if (ppercents == NULL)
+			psamples= calloc(nr_percent, sizeof(double));
+			if (ppercents == NULL || psamples == NULL) {
 				return -1;
+			}
 		}
 
 		for (i = 0; i < nr_percent; i++) {

@@ -712,9 +719,10 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 					notes->src->lines ? i : evsel->idx + i,
 					offset,
 					next ? next->offset : (s64) len,
-					&path);
+					&path, &samples);
 
 			ppercents[i] = percent;
+			psamples[i] = samples;
 			if (percent > max_percent)
 				max_percent = percent;
 		}

@@ -752,8 +760,13 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 
 		for (i = 0; i < nr_percent; i++) {
 			percent = ppercents[i];
+			samples = psamples[i];
 			color = get_percent_color(percent);
-			color_fprintf(stdout, color, " %7.2f", percent);
+
+			if (symbol_conf.show_total_period)
+				color_fprintf(stdout, color, " %7.0f", samples);
+			else
+				color_fprintf(stdout, color, " %7.2f", percent);
 		}
 
 		printf(" :	");

@@ -763,6 +776,9 @@ static int disasm_line__print(struct disasm_line *dl, struct symbol *sym, u64 st
 		if (ppercents != &percent)
 			free(ppercents);
 
+		if (psamples != &samples)
+			free(psamples);
+
 	} else if (max_lines && printed >= max_lines)
 		return 1;
 	else {

tools/perf/util/annotate.h +2 -1

index cadbdc9..b3ffb87 100644
@@ -72,7 +72,7 @@ struct disasm_line *disasm__get_next_ip_line(struct list_head *head, struct disa
 int disasm_line__scnprintf(struct disasm_line *dl, char *bf, size_t size, bool raw);
 size_t disasm__fprintf(struct list_head *head, FILE *fp);
 double disasm__calc_percent(struct annotation *notes, int evidx, s64 offset,
-			    s64 end, const char **path);
+			    s64 end, const char **path, double *samples);
 
 struct sym_hist {
 	u64		sum;

@@ -81,6 +81,7 @@ struct sym_hist {
 
 struct source_line_percent {
 	double		percent;
+	double          samples;
 	double		percent_sum;
 };

Signature · 1 line

2.1.4