Skip to contentSkip to conversation

perf, tools: Refactor and support interval and CSV metrics v2

PATCH New Andi Kleen 3 participants 13 messages Aug 4, 2015 – Aug 6, 2015 perf events

lore
Share & tools
lore

Andi Kleen

author
#0 lore raw

[v2: Addressed (near) all review feedback. No manpage updates so far.
Add support for --per-core metrics. Various cleanups.]

Currently perf stat does not support printing computed metrics for interval (-I xxx) or CSV (-x,) mode. For example IPC or TSX metrics over time are quite useful to know.

This patch implements them. The main obstacle was that the
metrics printing was all open coded all over the metrics computation code. The second patch refactors the metrics printing to work through call backs that can be more easily changed. This also cleans up the metrics printing significantly. The indentation is now handled through printf, no more need to manually count spaces.

Then based on that it implements metrics printing for CSV and interval mode.

Example output:

% perf stat -I1000 -a sleep 1

#          time              counts unit events                    metric                              multiplex
     1.001301370       12020.049593      task-clock (msec)                                             (100.00%)
     1.001301370              3,952      context-switches          #    0.329 K/sec                    (100.00%)
     1.001301370                 69      cpu-migrations            #    0.006 K/sec                    (100.00%)
     1.001301370                 76      page-faults               #    0.006 K/sec                  
     1.001301370        386,582,789      cycles                    #    0.032 GHz                      (100.00%)
     1.001301370        716,441,544      stalled-cycles-frontend   #  185.33% frontend cycles idle     (100.00%)
     1.001301370    <not supported>      stalled-cycles-backend   
     1.001301370        101,751,678      instructions              #    0.26  insn per cycle         
     1.001301370                                                   #    7.04  stalled cycles per insn  (100.00%)
     1.001301370         20,914,692      branches                  #    1.740 M/sec                    (100.00%)
     1.001301370          1,943,630      branch-misses             #    9.29% of all branches        

CSV mode

% perf stat -x, -I1000 -a sleep 1

     1.000852081,12016.143006,,task-clock
     1.000852081,4457,,context-switches,12015168277,100.00,0.371,K/sec
     1.000852081,50,,cpu-migrations,12014024424,100.00,0.004,K/sec
     1.000852081,76,,page-faults,12013076716,100.00,0.006,K/sec
     1.000852081,515854373,,cycles,12011235336,100.00,0.043,GHz
     1.000852081,1030742150,,stalled-cycles-frontend,12010984057,100.00,199.81,frontend cycles idle
     1.000852081,<not supported>,,stalled-cycles-backend,0,100.00
     1.000852081,116782495,,instructions,12011130729,100.00,0.23,insn per cycle
     1.000852081,,,,12011130729,100.00,8.83,stalled cycles per insn
     1.000852081,23748237,,branches,12010745125,100.00,1.976,M/sec
     1.000852081,1976560,,branch-misses,12010501884,100.00,8.32,of all branches

Available in
git://git.kernel.org/pub/scm/linux/kernel/git/ak/linux-misc perf/stat-metrics-2

author
#1 lore raw

PATCH 1/8 perf, tools: Remove trail argument to color vsprintf

From: Jiri Olsa <[email protected]>

Seems like it's always '\n' through color_fprintf_ln, which is not used at all, removing.. ;-)

---
 tools/perf/util/color.c | 16 ++--------------
 tools/perf/util/color.h |  1 -
 2 files changed, 2 insertions(+), 15 deletions(-)
tools/perf/util/color.c +2 -14
index 55355b3..ff051d2 100644
@@ -68,7 +68,7 @@ static int __color_vsnprintf(char *bf, size_t size, const char *color,
 }
 
 static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
-		va_list args, const char *trail)
+		va_list args)
 {
 	int r = 0;
 
@@ -87,8 +87,6 @@ static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 	r += vfprintf(fp, fmt, args);
 	if (perf_use_color_default && *color)
 		r += fprintf(fp, "%s", PERF_COLOR_RESET);
-	if (trail)
-		r += fprintf(fp, "%s", trail);
 	return r;
 }
 
@@ -100,7 +98,7 @@ int color_vsnprintf(char *bf, size_t size, const char *color,
 
 int color_vfprintf(FILE *fp, const char *color, const char *fmt, va_list args)
 {
-	return __color_vfprintf(fp, color, fmt, args, NULL);
+	return __color_vfprintf(fp, color, fmt, args);
 }
 
 int color_snprintf(char *bf, size_t size, const char *color,
@@ -126,16 +124,6 @@ int color_fprintf(FILE *fp, const char *color, const char *fmt, ...)
 	return r;
 }
 
-int color_fprintf_ln(FILE *fp, const char *color, const char *fmt, ...)
-{
-	va_list args;
-	int r;
-	va_start(args, fmt);
-	r = __color_vfprintf(fp, color, fmt, args, "\n");
-	va_end(args);
-	return r;
-}
-
 /*
  * This function splits the buffer by newlines and colors the lines individually.
  *
tools/perf/util/color.h +0 -1
index 38146f9..a93997f 100644
@@ -35,7 +35,6 @@ int color_vsnprintf(char *bf, size_t size, const char *color,
 int color_vfprintf(FILE *fp, const char *color, const char *fmt, va_list args);
 int color_fprintf(FILE *fp, const char *color, const char *fmt, ...);
 int color_snprintf(char *bf, size_t size, const char *color, const char *fmt, ...);
-int color_fprintf_ln(FILE *fp, const char *color, const char *fmt, ...);
 int color_fwrite_lines(FILE *fp, const char *color, size_t count, const char *buf);
 int value_color_snprintf(char *bf, size_t size, const char *fmt, double value);
 int percent_color_snprintf(char *bf, size_t size, const char *fmt, ...);
Signature · 1 line
2.4.3
#2 lore raw

[tip:perf/core] perf tools: Remove trail argument to color vsprintf

perf tools: Remove trail argument to color vsprintf
Commit-ID:  8011de7ab3b10c5352f3f0708f517de2722b0957
Gitweb:     http://git.kernel.org/tip/8011de7ab3b10c5352f3f0708f517de2722b0957
Author:     Jiri Olsa <[email protected]>
AuthorDate: Mon, 3 Aug 2015 17:50:01 -0700
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Wed, 5 Aug 2015 16:44:02 -0300

perf tools: Remove trail argument to color vsprintf

Seems like it's always '\n' through color_fprintf_ln, which is not used at all, removing.. ;-)

---
 tools/perf/util/color.c | 16 ++--------------
 tools/perf/util/color.h |  1 -
 2 files changed, 2 insertions(+), 15 deletions(-)
tools/perf/util/color.c +2 -14
index 55355b3..ff051d2 100644
@@ -68,7 +68,7 @@ static int __color_vsnprintf(char *bf, size_t size, const char *color,
 }
 
 static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
-		va_list args, const char *trail)
+		va_list args)
 {
 	int r = 0;
 
@@ -87,8 +87,6 @@ static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 	r += vfprintf(fp, fmt, args);
 	if (perf_use_color_default && *color)
 		r += fprintf(fp, "%s", PERF_COLOR_RESET);
-	if (trail)
-		r += fprintf(fp, "%s", trail);
 	return r;
 }
 
@@ -100,7 +98,7 @@ int color_vsnprintf(char *bf, size_t size, const char *color,
 
 int color_vfprintf(FILE *fp, const char *color, const char *fmt, va_list args)
 {
-	return __color_vfprintf(fp, color, fmt, args, NULL);
+	return __color_vfprintf(fp, color, fmt, args);
 }
 
 int color_snprintf(char *bf, size_t size, const char *color,
@@ -126,16 +124,6 @@ int color_fprintf(FILE *fp, const char *color, const char *fmt, ...)
 	return r;
 }
 
-int color_fprintf_ln(FILE *fp, const char *color, const char *fmt, ...)
-{
-	va_list args;
-	int r;
-	va_start(args, fmt);
-	r = __color_vfprintf(fp, color, fmt, args, "\n");
-	va_end(args);
-	return r;
-}
-
 /*
  * This function splits the buffer by newlines and colors the lines individually.
  *
tools/perf/util/color.h +0 -1
index 38146f9..a93997f 100644
@@ -35,7 +35,6 @@ int color_vsnprintf(char *bf, size_t size, const char *color,
 int color_vfprintf(FILE *fp, const char *color, const char *fmt, va_list args);
 int color_fprintf(FILE *fp, const char *color, const char *fmt, ...);
 int color_snprintf(char *bf, size_t size, const char *color, const char *fmt, ...);
-int color_fprintf_ln(FILE *fp, const char *color, const char *fmt, ...);
 int color_fwrite_lines(FILE *fp, const char *color, size_t count, const char *buf);
 int value_color_snprintf(char *bf, size_t size, const char *fmt, double value);
 int percent_color_snprintf(char *bf, size_t size, const char *fmt, ...);
author
#3 lore raw

PATCH 2/8 perf, tools: Do not include escape sequences in color_vfprintf return

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

color_vprintf was including the length of the invisible escape sequences in its return argument. Don't include them to make the return value usable for indentation calculations.

v2: Add comment, rebase

---
 tools/perf/util/color.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)
tools/perf/util/color.c +3 -2
index ff051d2..9b95654 100644
@@ -67,6 +67,7 @@ static int __color_vsnprintf(char *bf, size_t size, const char *color,
 	return r;
 }
 
+/* Colors are not included in return value */
 static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 		va_list args)
 {
@@ -83,10 +84,10 @@ static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 	}
 
 	if (perf_use_color_default && *color)
-		r += fprintf(fp, "%s", color);
+		fprintf(fp, "%s", color);
 	r += vfprintf(fp, fmt, args);
 	if (perf_use_color_default && *color)
-		r += fprintf(fp, "%s", PERF_COLOR_RESET);
+		fprintf(fp, "%s", PERF_COLOR_RESET);
 	return r;
 }
 
Signature · 1 line
2.4.3
#4 lore raw

[tip:perf/core] perf tools: Do not include escape sequences in color_vfprintf return

perf tools: Do not include escape sequences in color_vfprintf return
Commit-ID:  b7a001d2067830a98e65d1bbbf99a6d435d70616
Gitweb:     http://git.kernel.org/tip/b7a001d2067830a98e65d1bbbf99a6d435d70616
Author:     Andi Kleen <[email protected]>
AuthorDate: Mon, 3 Aug 2015 17:50:02 -0700
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Wed, 5 Aug 2015 16:46:06 -0300

perf tools: Do not include escape sequences in color_vfprintf return

color_vprintf was including the length of the invisible escape sequences in its return argument. Don't include them to make the return value usable for indentation calculations.

v2: Add comment, rebase

---
 tools/perf/util/color.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)
tools/perf/util/color.c +3 -2
index ff051d2..9b95654 100644
@@ -67,6 +67,7 @@ static int __color_vsnprintf(char *bf, size_t size, const char *color,
 	return r;
 }
 
+/* Colors are not included in return value */
 static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 		va_list args)
 {
@@ -83,10 +84,10 @@ static int __color_vfprintf(FILE *fp, const char *color, const char *fmt,
 	}
 
 	if (perf_use_color_default && *color)
-		r += fprintf(fp, "%s", color);
+		fprintf(fp, "%s", color);
 	r += vfprintf(fp, fmt, args);
 	if (perf_use_color_default && *color)
-		r += fprintf(fp, "%s", PERF_COLOR_RESET);
+		fprintf(fp, "%s", PERF_COLOR_RESET);
 	return r;
 }
 
author
#5 lore raw

PATCH 3/8 perf, tools, stat: Move sw clock metrics printout to stat-shadow

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

The sw clock metrics printing was missed in the earlier move to stat-shadow of all the other metric printouts. Move it too.

---
 tools/perf/builtin-stat.c     | 9 ---------
 tools/perf/util/stat-shadow.c | 4 ++++
 2 files changed, 4 insertions(+), 9 deletions(-)
tools/perf/builtin-stat.c +0 -9
index d99d850..baca81d 100644
@@ -642,15 +642,6 @@ static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 
 	if (evsel->cgrp)
 		fprintf(output, "%s%s", csv_sep, evsel->cgrp->name);
-
-	if (csv_output || interval)
-		return;
-
-	if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK))
-		fprintf(output, " # %8.3f CPUs utilized          ",
-			avg / avg_stats(&walltime_nsecs_stats));
-	else
-		fprintf(output, "                                   ");
 }
 
 static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
tools/perf/util/stat-shadow.c +4 -0
index 53e8bb7..88d23d9 100644
@@ -415,6 +415,10 @@ void perf_stat__print_shadow_stats(FILE *out, struct perf_evsel *evsel,
 			ratio = total / avg;
 
 		fprintf(out, " # %8.0f cycles / elision       ", ratio);
+	} else if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK) &&
+		   (ratio = avg_stats(&walltime_nsecs_stats)) != 0) {
+		fprintf(output, " # %8.3f CPUs utilized          ",
+				     avg / ratio);
 	} else if (runtime_nsecs_stats[cpu].n != 0) {
 		char unit = 'M';
 
Signature · 1 line
2.4.3
author
#6 lore raw

PATCH 4/8 perf, tools, stat: Abstract stat metrics printing

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

Abstract the printing of shadow metrics. Instead of every metric calling fprintf directly and taking care of indentation, use two call backs: one to print metrics and another to start a new line.

This will allow adding metrics to CSV mode and also using them for other purposes.

The computation of padding is now done in the central callback, instead of every metric doing it manually. This makes it easier to add new metrics.

v2: Refactor functions, printout now does more. Move shadow printing.

---
 tools/perf/builtin-stat.c     |  96 +++++++++++++++++--------
 tools/perf/util/stat-shadow.c | 158 ++++++++++++++++++++++--------------------
 tools/perf/util/stat.h        |  10 ++-
 3 files changed, 158 insertions(+), 106 deletions(-)
tools/perf/builtin-stat.c +68 -28
index baca81d..31395c8 100644
@@ -617,6 +617,47 @@ static void aggr_printout(struct perf_evsel *evsel, int id, int nr)
 	}
 }
 
+struct outstate {
+	FILE *fh;
+};
+
+#define BASE_INDENT 41
+#define AGGR_INDENT  8
+#define METRIC_LEN  35
+#define NA_INDENT   16
+
+static void new_line_no_aggr_std(void *ctx)
+{
+	struct outstate *os = ctx;
+	fprintf(os->fh, "\n%*s", BASE_INDENT + NA_INDENT, "");
+}
+
+static void new_line_std(void *ctx)
+{
+	struct outstate *os = ctx;
+	fprintf(os->fh, "\n%-*s", BASE_INDENT + AGGR_INDENT, "");
+}
+
+static void print_metric_std(void *ctx, const char *color, const char *fmt,
+			     const char *unit, double val)
+{
+	struct outstate *os = ctx;
+	FILE *out = os->fh;
+	int n;
+
+	if (unit == NULL) {
+		fprintf(out, "%-*s", METRIC_LEN, "");
+		return;
+	}
+
+	n = fprintf(out, " # ");
+	if (color)
+		n += color_fprintf(out, color, fmt, val);
+	else
+		n += fprintf(out, fmt, val);
+	fprintf(out, " %-*s", METRIC_LEN - n - 1, unit);
+}
+
 static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 {
 	double msecs = avg / 1e6;
@@ -648,7 +689,6 @@ static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 {
 	double sc =  evsel->scale;
 	const char *fmt;
-	int cpu = cpu_map__id_to_cpu(id);
 
 	if (csv_output) {
 		fmt = sc != 1.0 ?  "%.2f%s" : "%.0f%s";
@@ -661,9 +701,6 @@ static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 
 	aggr_printout(evsel, id, nr);
 
-	if (aggr_mode == AGGR_GLOBAL)
-		cpu = 0;
-
 	fprintf(output, fmt, avg, csv_sep);
 
 	if (evsel->unit)
@@ -676,10 +713,30 @@ static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 	if (evsel->cgrp)
 		fprintf(output, "%s%s", csv_sep, evsel->cgrp->name);
 
-	if (csv_output || interval)
-		return;
+}
 
-	perf_stat__print_shadow_stats(output, evsel, avg, cpu, aggr_mode);
+static void printout(int id, int nr, struct perf_evsel *counter, double uval)
+{
+	struct outstate os = { .fh = output };
+	print_metric_t pm = print_metric_std;
+	void (*nl)(void *);
+
+	if (aggr_mode == AGGR_NONE)
+		nl = new_line_no_aggr_std;
+	else
+		nl = new_line_std;
+
+	if (nsec_counter(counter))
+		nsec_printout(id, nr, counter, uval);
+	else
+		abs_printout(id, nr, counter, uval);
+
+	perf_stat__print_shadow_stats(counter, uval,
+				      aggr_mode == AGGR_GLOBAL ? 0 :
+				      cpu_map__id_to_cpu(id),
+				      pm,
+				      nl,
+				      &os);
 }
 
 static void print_aggr(char *prefix)
@@ -735,12 +792,7 @@ static void print_aggr(char *prefix)
 				continue;
 			}
 			uval = val * counter->scale;
-
-			if (nsec_counter(counter))
-				nsec_printout(id, nr, counter, uval);
-			else
-				abs_printout(id, nr, counter, uval);
-
+			printout(id, nr, counter, uval);
 			if (!csv_output)
 				print_noise(counter, 1.0);
 
@@ -770,11 +822,7 @@ static void print_aggr_thread(struct perf_evsel *counter, char *prefix)
 			fprintf(output, "%s", prefix);
 
 		uval = val * counter->scale;
-
-		if (nsec_counter(counter))
-			nsec_printout(thread, 0, counter, uval);
-		else
-			abs_printout(thread, 0, counter, uval);
+		printout(thread, 0, counter, uval);
 
 		if (!csv_output)
 			print_noise(counter, 1.0);
@@ -823,11 +871,7 @@ static void print_counter_aggr(struct perf_evsel *counter, char *prefix)
 	}
 
 	uval = avg * counter->scale;
-
-	if (nsec_counter(counter))
-		nsec_printout(-1, 0, counter, uval);
-	else
-		abs_printout(-1, 0, counter, uval);
+	printout(-1, 0, counter, uval);
 
 	print_noise(counter, avg);
 
@@ -879,11 +923,7 @@ static void print_counter(struct perf_evsel *counter, char *prefix)
 		}
 
 		uval = val * counter->scale;
-
-		if (nsec_counter(counter))
-			nsec_printout(cpu, 0, counter, uval);
-		else
-			abs_printout(cpu, 0, counter, uval);
+		printout(cpu, 0, counter, uval);
 
 		if (!csv_output)
 			print_noise(counter, 1.0);
tools/perf/util/stat-shadow.c +82 -76

330 lines not on this page · raw message

tools/perf/util/stat.h +8 -2
index 1cfbe0a..152322d 100644
@@ -83,11 +83,17 @@ void perf_stat_evsel_id_init(struct perf_evsel *evsel);
 
 extern struct stats walltime_nsecs_stats;
 
+typedef void (*print_metric_t)(void *ctx, const char *color, const char *unit,
+			       const char *fmt, double val);
+
 void perf_stat__reset_shadow_stats(void);
 void perf_stat__update_shadow_stats(struct perf_evsel *counter, u64 *count,
 				    int cpu);
-void perf_stat__print_shadow_stats(FILE *out, struct perf_evsel *evsel,
-				   double avg, int cpu, enum aggr_mode aggr);
+void perf_stat__print_shadow_stats(struct perf_evsel *evsel,
+				   double avg, int cpu,
+				   print_metric_t print_metric,
+				   void (*new_line)(void *ctx),
+				   void *ctx);
 
 struct perf_counts *perf_counts__new(int ncpus, int nthreads);
 void perf_counts__delete(struct perf_counts *counts);
Signature · 1 line
2.4.3
author
#7 lore raw

PATCH 5/8 perf, tools, stat: Add support for metrics in interval mode

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

Now that we can modify the metrics printout functions easily, it's straight forward to support metric printing for interval mode. All that is needed is to print the time stamp on every new line. Pass the prefix into the context and print it out.

---
 tools/perf/builtin-stat.c | 24 +++++++++++++++---------
 1 file changed, 15 insertions(+), 9 deletions(-)
tools/perf/builtin-stat.c +15 -9
index 31395c8..aea9350 100644
@@ -619,6 +619,9 @@ static void aggr_printout(struct perf_evsel *evsel, int id, int nr)
 
 struct outstate {
 	FILE *fh;
+	const char *prefix;
+	int nfields;
+	u64 run, ena;
 };
 
 #define BASE_INDENT 41
@@ -629,13 +632,13 @@ struct outstate {
 static void new_line_no_aggr_std(void *ctx)
 {
 	struct outstate *os = ctx;
-	fprintf(os->fh, "\n%*s", BASE_INDENT + NA_INDENT, "");
+	fprintf(os->fh, "\n%s%-*s", os->prefix, BASE_INDENT + NA_INDENT, "");
 }
 
 static void new_line_std(void *ctx)
 {
 	struct outstate *os = ctx;
-	fprintf(os->fh, "\n%-*s", BASE_INDENT + AGGR_INDENT, "");
+	fprintf(os->fh, "\n%s%-*s", os->prefix, BASE_INDENT + AGGR_INDENT, "");
 }
 
 static void print_metric_std(void *ctx, const char *color, const char *fmt,
@@ -712,12 +715,15 @@ static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 
 	if (evsel->cgrp)
 		fprintf(output, "%s%s", csv_sep, evsel->cgrp->name);
-
 }
 
-static void printout(int id, int nr, struct perf_evsel *counter, double uval)
+static void printout(int id, int nr, struct perf_evsel *counter, double uval,
+		     char *prefix)
 {
-	struct outstate os = { .fh = output };
+	struct outstate os = {
+		.fh = output,
+		.prefix = prefix ? prefix : ""
+	};
 	print_metric_t pm = print_metric_std;
 	void (*nl)(void *);
 
@@ -792,7 +798,7 @@ static void print_aggr(char *prefix)
 				continue;
 			}
 			uval = val * counter->scale;
-			printout(id, nr, counter, uval);
+			printout(id, nr, counter, uval, prefix);
 			if (!csv_output)
 				print_noise(counter, 1.0);
 
@@ -822,7 +828,7 @@ static void print_aggr_thread(struct perf_evsel *counter, char *prefix)
 			fprintf(output, "%s", prefix);
 
 		uval = val * counter->scale;
-		printout(thread, 0, counter, uval);
+		printout(thread, 0, counter, uval, prefix);
 
 		if (!csv_output)
 			print_noise(counter, 1.0);
@@ -871,7 +877,7 @@ static void print_counter_aggr(struct perf_evsel *counter, char *prefix)
 	}
 
 	uval = avg * counter->scale;
-	printout(-1, 0, counter, uval);
+	printout(-1, 0, counter, uval, prefix);
 
 	print_noise(counter, avg);
 
@@ -923,7 +929,7 @@ static void print_counter(struct perf_evsel *counter, char *prefix)
 		}
 
 		uval = val * counter->scale;
-		printout(cpu, 0, counter, uval);
+		printout(cpu, 0, counter, uval, prefix);
 
 		if (!csv_output)
 			print_noise(counter, 1.0);
Signature · 1 line
2.4.3
author
#8 lore raw

PATCH 6/8 perf, tools, stat: Move noise/running printing into printout

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

Move the running/noise printing into printout to avoid duplicated code in the callers.

---
 tools/perf/builtin-stat.c | 33 +++++++++++----------------------
 1 file changed, 11 insertions(+), 22 deletions(-)
tools/perf/builtin-stat.c +11 -22
index aea9350..949b45f 100644
@@ -718,7 +718,7 @@ static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 }
 
 static void printout(int id, int nr, struct perf_evsel *counter, double uval,
-		     char *prefix)
+		     char *prefix, u64 run, u64 ena, double noise)
 {
 	struct outstate os = {
 		.fh = output,
@@ -743,6 +743,12 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 				      pm,
 				      nl,
 				      &os);
+
+	if (!csv_output) {
+		print_noise(counter, noise);
+		if (run != ena)
+			fprintf(output, "  (%.2f%%)", 100.0 * run / ena);
+	}
 }
 
 static void print_aggr(char *prefix)
@@ -798,11 +804,7 @@ static void print_aggr(char *prefix)
 				continue;
 			}
 			uval = val * counter->scale;
-			printout(id, nr, counter, uval, prefix);
-			if (!csv_output)
-				print_noise(counter, 1.0);
-
-			print_running(run, ena);
+			printout(id, nr, counter, uval, prefix, run, ena, 1.0);
 			fputc('\n', output);
 		}
 	}
@@ -828,12 +830,7 @@ static void print_aggr_thread(struct perf_evsel *counter, char *prefix)
 			fprintf(output, "%s", prefix);
 
 		uval = val * counter->scale;
-		printout(thread, 0, counter, uval, prefix);
-
-		if (!csv_output)
-			print_noise(counter, 1.0);
-
-		print_running(run, ena);
+		printout(thread, 0, counter, uval, prefix, run, ena, 1.0);
 		fputc('\n', output);
 	}
 }
@@ -877,11 +874,7 @@ static void print_counter_aggr(struct perf_evsel *counter, char *prefix)
 	}
 
 	uval = avg * counter->scale;
-	printout(-1, 0, counter, uval, prefix);
-
-	print_noise(counter, avg);
-
-	print_running(avg_running, avg_enabled);
+	printout(-1, 0, counter, uval, prefix, avg_running, avg_enabled, avg);
 	fprintf(output, "\n");
 }
 
@@ -929,11 +922,7 @@ static void print_counter(struct perf_evsel *counter, char *prefix)
 		}
 
 		uval = val * counter->scale;
-		printout(cpu, 0, counter, uval, prefix);
-
-		if (!csv_output)
-			print_noise(counter, 1.0);
-		print_running(run, ena);
+		printout(cpu, 0, counter, uval, prefix, run, ena, 1.0);
 
 		fputc('\n', output);
 	}
Signature · 1 line
2.4.3
author
#9 lore raw

PATCH 7/8 perf, tools, stat: Implement CSV metrics output

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

Now support CSV output for metrics. With the new output callbacks this is relatively straight forward by creating new callbacks.

The new line callback needs to know the number of fields to skip them correctly

v2: Split out function argument changes

---
 tools/perf/builtin-stat.c | 62 +++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 62 insertions(+)
tools/perf/builtin-stat.c +62 -0
index 949b45f..40900c5 100644
@@ -661,6 +661,49 @@ static void print_metric_std(void *ctx, const char *color, const char *fmt,
 	fprintf(out, " %-*s", METRIC_LEN - n - 1, unit);
 }
 
+static void new_line_csv(void *ctx)
+{
+	struct outstate *os = ctx;
+	int i;
+
+	fputc('\n', os->fh);
+	if (os->prefix)
+		fprintf(os->fh, "%s%s", os->prefix, csv_sep);
+	for (i = 0; i < os->nfields; i++)
+		fputs(csv_sep, os->fh);
+}
+
+static void print_metric_csv(void *ctx,
+			     const char *color __maybe_unused,
+			     const char *fmt, const char *unit, double val)
+{
+	struct outstate *os = ctx;
+	FILE *out = os->fh;
+	char buf[64], *vals, *ends;
+
+	if (unit == NULL) {
+		fprintf(out, "%s%s%s%s", csv_sep, csv_sep, csv_sep, csv_sep);
+		return;
+	}
+	fprintf(out, "%s%" PRIu64 "%s%.2f%s",
+		csv_sep,
+		os->run,
+		csv_sep,
+		os->ena ? 100.0 * os->run / os->ena : 100.0,
+		csv_sep);
+	snprintf(buf, sizeof(buf), fmt, val);
+	vals = buf;
+	while (isspace(*vals))
+		vals++;
+	ends = vals;
+	while (isdigit(*ends) || *ends == '.')
+		ends++;
+	*ends = 0;
+	while (isspace(*unit))
+		unit++;
+	fprintf(out, "%s%s%s", vals, csv_sep, unit);
+}
+
 static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 {
 	double msecs = avg / 1e6;
@@ -732,6 +775,25 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 	else
 		nl = new_line_std;
 
+	if (csv_output) {
+		static int aggr_fields[] = {
+			[AGGR_GLOBAL] = 0,
+			[AGGR_THREAD] = 1,
+			[AGGR_NONE] = 1,
+			[AGGR_SOCKET] = 2,
+			[AGGR_CORE] = 2,
+		};
+
+		pm = print_metric_csv;
+		nl = new_line_csv;
+		os.nfields = 1;
+		os.nfields += aggr_fields[aggr_mode];
+		if (counter->cgrp)
+			os.nfields++;
+		os.run = run;
+		os.ena = ena;
+	}
+
 	if (nsec_counter(counter))
 		nsec_printout(id, nr, counter, uval);
 	else
Signature · 1 line
2.4.3
author
#10 lore raw

PATCH 8/8 perf, tools: Support metrics in --per-core/socket mode

In reply to Andi Kleen

From: Andi Kleen <[email protected]>

Enable metrics printing in --per-core / --per-socket mode. We need to save the shadow metrics in a unique place. Always use the first CPU in the aggregation. Then use the same CPU to retrieve the shadow value later.

Example output:

% perf stat --per-core -a ./BC1s

Performance counter stats for 'system wide':

S0-C0           2        2966.020381      task-clock (msec)         #    2.004 CPUs utilized            (100.00%)
S0-C0           2                 49      context-switches          #    0.017 K/sec                    (100.00%)
S0-C0           2                  4      cpu-migrations            #    0.001 K/sec                    (100.00%)
S0-C0           2                467      page-faults               #    0.157 K/sec
S0-C0           2      4,599,061,773      cycles                    #    1.551 GHz                      (100.00%)
S0-C0           2      9,755,886,883      instructions              #    2.12  insn per cycle           (100.00%)
S0-C0           2      1,906,272,125      branches                  #  642.704 M/sec                    (100.00%)
S0-C0           2         81,180,867      branch-misses             #    4.26% of all branches
S0-C1           2        2965.995373      task-clock (msec)         #    2.003 CPUs utilized            (100.00%)
S0-C1           2                 62      context-switches          #    0.021 K/sec                    (100.00%)
S0-C1           2                  8      cpu-migrations            #    0.003 K/sec                    (100.00%)
S0-C1           2                281      page-faults               #    0.095 K/sec
S0-C1           2          6,347,290      cycles                    #    0.002 GHz                      (100.00%)
S0-C1           2          4,654,156      instructions              #    0.73  insn per cycle           (100.00%)
S0-C1           2            947,121      branches                  #    0.319 M/sec                    (100.00%)
S0-C1           2             37,322      branch-misses             #    3.94% of all branches
       1.480409747 seconds time elapsed
---
 tools/perf/builtin-stat.c | 45 +++++++++++++++++++++++++++++++++++++++++++--
 1 file changed, 43 insertions(+), 2 deletions(-)
tools/perf/builtin-stat.c +43 -2
index 40900c5..33b58c0 100644
@@ -731,6 +731,22 @@ static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 		fprintf(output, "%s%s", csv_sep, evsel->cgrp->name);
 }
 
+static int first_shadow_cpu(struct perf_evsel *evsel, int id)
+{
+	int i;
+
+	if (aggr_get_id == NULL)
+		return 0;
+
+	for (i = 0; i < perf_evsel__nr_cpus(evsel); i++) {
+		int cpu2 = perf_evsel__cpus(evsel)->map[i];
+
+		if (aggr_get_id(evsel_list->cpus, cpu2) == id)
+			return cpu2;
+	}
+	return 0;
+}
+
 static void abs_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 {
 	double sc =  evsel->scale;
@@ -800,8 +816,7 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 		abs_printout(id, nr, counter, uval);
 
 	perf_stat__print_shadow_stats(counter, uval,
-				      aggr_mode == AGGR_GLOBAL ? 0 :
-				      cpu_map__id_to_cpu(id),
+				      first_shadow_cpu(counter, id),
 				      pm,
 				      nl,
 				      &os);
@@ -813,6 +828,30 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 	}
 }
 
+static void aggr_update_shadow(void)
+{
+	int cpu, cpu2, s2, id, s;
+	u64 val;
+	struct perf_evsel *counter;
+
+	for (s = 0; s < aggr_map->nr; s++) {
+		id = aggr_map->map[s];
+		evlist__for_each(evsel_list, counter) {
+			val = 0;
+			for (cpu = 0; cpu < perf_evsel__nr_cpus(counter); cpu++) {
+				cpu2 = perf_evsel__cpus(counter)->map[cpu];
+				s2 = aggr_get_id(evsel_list->cpus, cpu2);
+				if (s2 != id)
+					continue;
+				val += perf_counts(counter->counts, cpu, 0)->val;
+			}
+			val = scale_val(counter, val);
+			perf_stat__update_shadow_stats(counter, &val,
+						       first_shadow_cpu(counter, id));
+		}
+	}
+}
+
 static void print_aggr(char *prefix)
 {
 	struct perf_evsel *counter;
@@ -823,6 +862,8 @@ static void print_aggr(char *prefix)
 	if (!(aggr_map || aggr_get_id))
 		return;
 
+	aggr_update_shadow();
+
 	for (s = 0; s < aggr_map->nr; s++) {
 		id = aggr_map->map[s];
 		evlist__for_each(evsel_list, counter) {
Signature · 1 line
2.4.3
#11 lore raw
In reply to Andi Kleen
Quoted 46 lines · Andi Kleen

[v2: Addressed (near) all review feedback. No manpage updates so far.
Add support for --per-core metrics. Various cleanups.]

Currently perf stat does not support printing computed metrics for interval (-I xxx) or CSV (-x,) mode. For example IPC or TSX metrics over time are quite useful to know.

This patch implements them. The main obstacle was that the
metrics printing was all open coded all over the metrics computation code. The second patch refactors the metrics printing to work through call backs that can be more easily changed. This also cleans up the metrics printing significantly. The indentation is now handled through printf, no more need to manually count spaces.

Then based on that it implements metrics printing for CSV and interval mode.

Example output:

% perf stat -I1000 -a sleep 1

#          time              counts unit events                    metric                              multiplex
     1.001301370       12020.049593      task-clock (msec)                                             (100.00%)
     1.001301370              3,952      context-switches          #    0.329 K/sec                    (100.00%)
     1.001301370                 69      cpu-migrations            #    0.006 K/sec                    (100.00%)
     1.001301370                 76      page-faults               #    0.006 K/sec                  
     1.001301370        386,582,789      cycles                    #    0.032 GHz                      (100.00%)
     1.001301370        716,441,544      stalled-cycles-frontend   #  185.33% frontend cycles idle     (100.00%)
     1.001301370    <not supported>      stalled-cycles-backend   
     1.001301370        101,751,678      instructions              #    0.26  insn per cycle         
     1.001301370                                                   #    7.04  stalled cycles per insn  (100.00%)
     1.001301370         20,914,692      branches                  #    1.740 M/sec                    (100.00%)
     1.001301370          1,943,630      branch-misses             #    9.29% of all branches        

CSV mode

% perf stat -x, -I1000 -a sleep 1

     1.000852081,12016.143006,,task-clock
     1.000852081,4457,,context-switches,12015168277,100.00,0.371,K/sec
     1.000852081,50,,cpu-migrations,12014024424,100.00,0.004,K/sec
     1.000852081,76,,page-faults,12013076716,100.00,0.006,K/sec
     1.000852081,515854373,,cycles,12011235336,100.00,0.043,GHz
     1.000852081,1030742150,,stalled-cycles-frontend,12010984057,100.00,199.81,frontend cycles idle
     1.000852081,<not supported>,,stalled-cycles-backend,0,100.00
     1.000852081,116782495,,instructions,12011130729,100.00,0.23,insn per cycle
     1.000852081,,,,12011130729,100.00,8.83,stalled cycles per insn
     1.000852081,23748237,,branches,12010745125,100.00,1.976,M/sec
     1.000852081,1976560,,branch-misses,12010501884,100.00,8.32,of all branches
Quoted 2 lines

Available in
git://git.kernel.org/pub/scm/linux/kernel/git/ak/linux-misc perf/stat-metrics-2

got build failure:

CC builtin-stat.o
builtin-stat.c: In function ‘aggr_update_shadow’:
builtin-stat.c:848:10: error: implicit declaration of function ‘scale_val’ [-Werror=implicit-function-declaration]

    val = scale_val(counter, val);
          ^
builtin-stat.c:848:4: error: nested extern declaration of ‘scale_val’ [-Werror=nested-externs]
    val = scale_val(counter, val);
    ^

cc1: all warnings being treated as errors /home/jolsa/kernel/linux-perf/tools/build/Makefile.build:68: recipe for target 'builtin-stat.o' failed make[2]: *** [builtin-stat.o] Error 1
Makefile.perf:296: recipe for target 'perf-in.o' failed
make[1]: *** [perf-in.o] Error 2
Makefile:68: recipe for target 'all' failed
make: *** [all] Error 2

jirka

author
#12 lore raw
Quoted 2 lines
    ^

cc1: all warnings being treated as errors

Sorry mistake in refactoring. I also forgot to include one patch.

I'll fix this and repost (and also add the man page)

-Andi