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


Groups > linux.kernel > #1336848 > unrolled thread

[PATCH 2/6] perf, tools, stat: Implement CSV metrics output

Started byAndi Kleen <andi@firstfloor.org>
First post2016-02-17 23:50 +0100
Last post2016-02-21 19:00 +0100
Articles 6 — 3 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.


Contents

  [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Andi Kleen <andi@firstfloor.org> - 2016-02-17 23:50 +0100
    Re: [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-02-18 18:10 +0100
      Re: [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Andi Kleen <andi@firstfloor.org> - 2016-02-18 18:40 +0100
        Re: [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Jiri Olsa <jolsa@redhat.com> - 2016-02-21 19:00 +0100
          Re: [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Andi Kleen <andi@firstfloor.org> - 2016-02-22 17:30 +0100
    Re: [PATCH 2/6] perf, tools, stat: Implement CSV metrics output Jiri Olsa <jolsa@redhat.com> - 2016-02-21 19:00 +0100

#1336848 — [PATCH 2/6] perf, tools, stat: Implement CSV metrics output

FromAndi Kleen <andi@firstfloor.org>
Date2016-02-17 23:50 +0100
Subject[PATCH 2/6] perf, tools, stat: Implement CSV metrics output
Message-ID<r3j50-4A2-39@gated-at.bofh.it>
From: Andi Kleen <ak@linux.intel.com>

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

This allows to easily plot metrics from CSV files.

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

Example output before:

% perf stat -x, true
0.200687,,task-clock,200687,100.00
0,,context-switches,200687,100.00
0,,cpu-migrations,200687,100.00
40,,page-faults,200687,100.00
730871,,cycles,203601,100.00
551056,,stalled-cycles-frontend,203601,100.00
<not supported>,,stalled-cycles-backend,0,100.00
385523,,instructions,203601,100.00
78028,,branches,203601,100.00
3946,,branch-misses,203601,100.00

After:

% perf stat -x, true
.502457,,task-clock,502457,100.00,0.485,CPUs utilized
0,,context-switches,502457,100.00,0.000,K/sec
0,,cpu-migrations,502457,100.00,0.000,K/sec
45,,page-faults,502457,100.00,0.090,M/sec
644692,,cycles,509102,100.00,1.283,GHz
423470,,stalled-cycles-frontend,509102,100.00,65.69,frontend cycles idle
<not supported>,,stalled-cycles-backend,0,100.00,,,,
492701,,instructions,509102,100.00,0.76,insn per cycle
,,,,,0.86,stalled cycles per insn
97767,,branches,509102,100.00,194.578,M/sec
4788,,branch-misses,509102,100.00,4.90,of all branches

or easier readable

perf stat  -x, -o x.csv true
[ak@tassilo hle]$ column -s, -t x.csv
0.490635                                 task-clock               490635  100.00  0.489    CPUs utilized
0                                        context-switches         490635  100.00  0.000    K/sec
0                                        cpu-migrations           490635  100.00  0.000    K/sec
45                                       page-faults              490635  100.00  0.092    M/sec
629080                                   cycles                   497698  100.00  1.282    GHz
409498                                   stalled-cycles-frontend  497698  100.00  65.09    frontend cycles idle
<not supported>                          stalled-cycles-backend   0       100.00
491424                                   instructions             497698  100.00  0.78     insn per cycle
                                                                                  0.83     stalled cycles per insn
97278                                    branches                 497698  100.00  198.270  M/sec
4569                                     branch-misses            497698  100.00  4.70     of all branches

Two new fields are added: metric value and metric name.

v2: Split out function argument changes
v3: Reenable metrics for real.
v4: Fix wrong hunk from refactoring.
v5: Remove extra "noise" printing (Jiri), but add it to the not counted case.
Print empty metrics for not counted.
v6: Avoid outputting metric on empty format.
v7: Print metric at the end
Signed-off-by: Andi Kleen <ak@linux.intel.com>
---
 tools/perf/builtin-stat.c | 76 ++++++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 72 insertions(+), 4 deletions(-)

diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index 86289df..6c2c1d2 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -739,6 +739,8 @@ struct outstate {
 	FILE *fh;
 	bool newline;
 	const char *prefix;
+	int  nfields;
+	u64  run, ena;
 };
 
 #define METRIC_LEN  35
@@ -789,6 +791,43 @@ 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 || fmt == NULL) {
+		fprintf(out, "%s%s%s%s", csv_sep, csv_sep, csv_sep, csv_sep);
+		return;
+	}
+	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%s", csv_sep, vals, csv_sep, unit);
+}
+
 static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg)
 {
 	FILE *output = stat_config.output;
@@ -860,6 +899,24 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 
 	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 = 3;
+		os.nfields += aggr_fields[stat_config.aggr_mode];
+		if (counter->cgrp)
+			os.nfields++;
+		os.run = run;
+		os.ena = ena;
+	}
 	if (run == 0 || ena == 0 || counter->counts->scaled == -1) {
 		aggr_printout(counter, id, nr);
 
@@ -880,7 +937,12 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 			fprintf(stat_config.output, "%s%s",
 				csv_sep, counter->cgrp->name);
 
+		if (!csv_output)
+			pm(&os, NULL, NULL, "", 0);
+		print_noise(counter, noise);
 		print_running(run, ena);
+		if (csv_output)
+			pm(&os, NULL, NULL, "", 0);
 		return;
 	}
 
@@ -893,14 +955,20 @@ static void printout(int id, int nr, struct perf_evsel *counter, double uval,
 	out.new_line = nl;
 	out.ctx = &os;
 
-	if (!csv_output)
-		perf_stat__print_shadow_stats(counter, uval,
+	if (csv_output) {
+		print_noise(counter, noise);
+		print_running(run, ena);
+	}
+
+	perf_stat__print_shadow_stats(counter, uval,
 				stat_config.aggr_mode == AGGR_GLOBAL ? 0 :
 				cpu_map__id_to_cpu(id),
 				&out);
 
-	print_noise(counter, noise);
-	print_running(run, ena);
+	if (!csv_output) {
+		print_noise(counter, noise);
+		print_running(run, ena);
+	}
 }
 
 static void print_aggr(char *prefix)
-- 
2.5.0

[toc] | [next] | [standalone]


#1337538

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-02-18 18:10 +0100
Message-ID<r3Afx-lQ-5@gated-at.bofh.it>
In reply to#1336848
Em Wed, Feb 17, 2016 at 02:44:01PM -0800, Andi Kleen escreveu:
> From: Andi Kleen <ak@linux.intel.com>
> 
> Now support CSV output for metrics. With the new output callbacks
> this is relatively straight forward by creating new callbacks.
> 
> This allows to easily plot metrics from CSV files.
> 
> The new line callback needs to know the number of fields to skip them
> correctly
> 
> Example output before:
> 
> % perf stat -x, true
> 0.200687,,task-clock,200687,100.00
> 0,,context-switches,200687,100.00
> 0,,cpu-migrations,200687,100.00
> 40,,page-faults,200687,100.00
> 730871,,cycles,203601,100.00
> 551056,,stalled-cycles-frontend,203601,100.00
> <not supported>,,stalled-cycles-backend,0,100.00
> 385523,,instructions,203601,100.00
> 78028,,branches,203601,100.00
> 3946,,branch-misses,203601,100.00
> 
> After:
> 
> % perf stat -x, true
> .502457,,task-clock,502457,100.00,0.485,CPUs utilized
> 0,,context-switches,502457,100.00,0.000,K/sec
> 0,,cpu-migrations,502457,100.00,0.000,K/sec
> 45,,page-faults,502457,100.00,0.090,M/sec
> 644692,,cycles,509102,100.00,1.283,GHz
> 423470,,stalled-cycles-frontend,509102,100.00,65.69,frontend cycles idle
> <not supported>,,stalled-cycles-backend,0,100.00,,,,
> 492701,,instructions,509102,100.00,0.76,insn per cycle
> ,,,,,0.86,stalled cycles per insn
> 97767,,branches,509102,100.00,194.578,M/sec
> 4788,,branch-misses,509102,100.00,4.90,of all branches

Testing here I noticed this new line with just commas:


[root@jouet ~]# perf stat -x, usleep 1 
0.268163,,task-clock,268163,100.00,0.484,CPUs utilized
1,,context-switches,268163,100.00,0.004,M/sec
0,,cpu-migrations,268163,100.00,0.000,K/sec
52,,page-faults,268163,100.00,0.194,M/sec
815922,,cycles,270746,100.00,3.043,GHz
<not supported>,,stalled-cycles-frontend,0,100.00,,,,
<not supported>,,stalled-cycles-backend,0,100.00,,,,
680198,,instructions,270746,100.00,0.83,insn per cycle
,,,,,,,,
136401,,branches,270746,100.00,508.650,M/sec
6995,,branch-misses,270746,100.00,5.13,of all branches
[root@jouet ~]#

Where before it wasn't there:

cat /tmp/before
0.282628,,task-clock,282628,100.00
1,,context-switches,282628,100.00
0,,cpu-migrations,282628,100.00
52,,page-faults,282628,100.00
861213,,cycles,285354,100.00
<not supported>,,stalled-cycles-frontend,0,100.00
<not supported>,,stalled-cycles-backend,0,100.00
686082,,instructions,285354,100.00
137846,,branches,285354,100.00
7142,,branch-misses,285354,100.00

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


#1337574

FromAndi Kleen <andi@firstfloor.org>
Date2016-02-18 18:40 +0100
Message-ID<r3AIz-yZ-35@gated-at.bofh.it>
In reply to#1337538
> Where before it wasn't there:
> 
> cat /tmp/before
> 0.282628,,task-clock,282628,100.00
> 1,,context-switches,282628,100.00
> 0,,cpu-migrations,282628,100.00
> 52,,page-faults,282628,100.00
> 861213,,cycles,285354,100.00
> <not supported>,,stalled-cycles-frontend,0,100.00
> <not supported>,,stalled-cycles-backend,0,100.00
> 686082,,instructions,285354,100.00
> 137846,,branches,285354,100.00
> 7142,,branch-misses,285354,100.00

This is intentional. See the standard perf output:


          521,232      instructions              #    0.63  insns per cycle        
                                                 #    1.13  stalled cycles per insn

So this line has multiple metrics. In CSV this is expressed as a mostly empty line.

-Andi

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


#1338900

FromJiri Olsa <jolsa@redhat.com>
Date2016-02-21 19:00 +0100
Message-ID<r4Gsz-16v-29@gated-at.bofh.it>
In reply to#1337574
On Thu, Feb 18, 2016 at 06:39:21PM +0100, Andi Kleen wrote:
> > Where before it wasn't there:
> > 
> > cat /tmp/before
> > 0.282628,,task-clock,282628,100.00
> > 1,,context-switches,282628,100.00
> > 0,,cpu-migrations,282628,100.00
> > 52,,page-faults,282628,100.00
> > 861213,,cycles,285354,100.00
> > <not supported>,,stalled-cycles-frontend,0,100.00
> > <not supported>,,stalled-cycles-backend,0,100.00
> > 686082,,instructions,285354,100.00
> > 137846,,branches,285354,100.00
> > 7142,,branch-misses,285354,100.00
> 
> This is intentional. See the standard perf output:
> 
> 
>           521,232      instructions              #    0.63  insns per cycle        
>                                                  #    1.13  stalled cycles per insn
> 
> So this line has multiple metrics. In CSV this is expressed as a mostly empty line.

it's intentional if you have data from stalled cycles counter
on cpu where this one is non supported you get blank line:

0.186177,,task-clock,186177,100.00,0.448,CPUs utilized
0,,context-switches,186177,100.00,0.000,K/sec
0,,cpu-migrations,186177,100.00,0.000,K/sec
43,,page-faults,186177,100.00,0.231,M/sec
567286,,cycles,187628,100.00,3.047,GHz
<not supported>,,stalled-cycles-frontend,0,100.00,,,,
<not supported>,,stalled-cycles-backend,0,100.00,,,,
456664,,instructions,187628,100.00,0.80,insn per cycle
,,,,,,,,
89069,,branches,187628,100.00,478.410,M/sec
3360,,branch-misses,187628,100.00,3.77,of all branches


which I think is wrong and we should not print

jirka

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


#1339704

FromAndi Kleen <andi@firstfloor.org>
Date2016-02-22 17:30 +0100
Message-ID<r51x0-8pa-15@gated-at.bofh.it>
In reply to#1338900
On Sun, Feb 21, 2016 at 05:39:40PM +0100, Jiri Olsa wrote:
> On Thu, Feb 18, 2016 at 06:39:21PM +0100, Andi Kleen wrote:
> > > Where before it wasn't there:
> > > 
> > > cat /tmp/before
> > > 0.282628,,task-clock,282628,100.00
> > > 1,,context-switches,282628,100.00
> > > 0,,cpu-migrations,282628,100.00
> > > 52,,page-faults,282628,100.00
> > > 861213,,cycles,285354,100.00
> > > <not supported>,,stalled-cycles-frontend,0,100.00
> > > <not supported>,,stalled-cycles-backend,0,100.00
> > > 686082,,instructions,285354,100.00
> > > 137846,,branches,285354,100.00
> > > 7142,,branch-misses,285354,100.00
> > 
> > This is intentional. See the standard perf output:
> > 
> > 
> >           521,232      instructions              #    0.63  insns per cycle        
> >                                                  #    1.13  stalled cycles per insn
> > 
> > So this line has multiple metrics. In CSV this is expressed as a mostly empty line.
> 
> it's intentional if you have data from stalled cycles counter
> on cpu where this one is non supported you get blank line:

I fixed this now by probing for the stalled cycles counters in advance.
That avoids a couple of other issues too, like the empty columns in
--metric-only, and even makes the output of standard perf stat
shorter.

-Andi

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


#1338896

FromJiri Olsa <jolsa@redhat.com>
Date2016-02-21 19:00 +0100
Message-ID<r4Gsz-16v-35@gated-at.bofh.it>
In reply to#1336848
On Wed, Feb 17, 2016 at 02:44:01PM -0800, Andi Kleen wrote:

SNIP

> ---
>  tools/perf/builtin-stat.c | 76 ++++++++++++++++++++++++++++++++++++++++++++---
>  1 file changed, 72 insertions(+), 4 deletions(-)
> 
> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> index 86289df..6c2c1d2 100644
> --- a/tools/perf/builtin-stat.c
> +++ b/tools/perf/builtin-stat.c
> @@ -739,6 +739,8 @@ struct outstate {
>  	FILE *fh;
>  	bool newline;
>  	const char *prefix;
> +	int  nfields;
> +	u64  run, ena;

what are outstate's ena and run being used for?

thanks,
jirka

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web