2022-11-23 18:14:33

by Namhyung Kim

[permalink] [raw]
Subject: [PATCH 13/15] perf stat: Fix JSON output in metric-only mode

It generated a broken JSON output when aggregation mode or cgroup is
used with --metric-only option. Also get rid of the header line and
make the output single line for each entry.

It needs to know whether the current metric is the first one or not.
So add 'first' field in the outstate and mark it false after printing.

Before:
# perf stat -a -j --metric-only true
{"unit" : "GHz"}{"unit" : "insn per cycle"}{"unit" : "branch-misses of all branches"}
{{"metric-value" : "0.797"}{"metric-value" : "1.65"}{"metric-value" : "0.89"}
^

# perf stat -a -j --metric-only --per-socket true
{"unit" : "GHz"}{"unit" : "insn per cycle"}{"unit" : "branch-misses of all branches"}
{"socket" : "S0", "aggregate-number" : 8, {"metric-value" : "0.295"}{"metric-value" : "1.88"}{"metric-value" : "0.64"}
^

After:
# perf stat -a -j --metric-only true
{"GHz" : "0.990", "insn per cycle" : "2.06", "branch-misses of all branches" : "0.59"}

# perf stat -a -j --metric-only --per-socket true
{"socket" : "S0", "aggregate-number" : 8, "GHz" : "0.439", "insn per cycle" : "2.14", "branch-misses of all branches" : "0.51"}

Signed-off-by: Namhyung Kim <[email protected]>
---
tools/perf/util/stat-display.c | 42 +++++++++++++++++++---------------
1 file changed, 24 insertions(+), 18 deletions(-)

diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c
index 335627e8542d..43640115454c 100644
--- a/tools/perf/util/stat-display.c
+++ b/tools/perf/util/stat-display.c
@@ -279,9 +279,6 @@ static void print_aggr_id_json(struct perf_stat_config *config,
{
FILE *output = config->output;

- if (!config->interval)
- fputc('{', output);
-
switch (config->aggr_mode) {
case AGGR_CORE:
fprintf(output, "\"core\" : \"S%d-D%d-C%d\", \"aggregate-number\" : %d, ",
@@ -335,6 +332,7 @@ static void aggr_printout(struct perf_stat_config *config,
struct outstate {
FILE *fh;
bool newline;
+ bool first;
const char *prefix;
int nfields;
int nr;
@@ -491,6 +489,7 @@ static void print_metric_only(struct perf_stat_config *config,

color_snprintf(str, sizeof(str), color ?: "", fmt, val);
fprintf(out, "%*s ", mlen, str);
+ os->first = false;
}

static void print_metric_only_csv(struct perf_stat_config *config __maybe_unused,
@@ -512,6 +511,7 @@ static void print_metric_only_csv(struct perf_stat_config *config __maybe_unused
ends++;
*ends = 0;
fprintf(out, "%s%s", vals, config->csv_sep);
+ os->first = false;
}

static void print_metric_only_json(struct perf_stat_config *config __maybe_unused,
@@ -532,7 +532,8 @@ static void print_metric_only_json(struct perf_stat_config *config __maybe_unuse
while (isdigit(*ends) || *ends == '.')
ends++;
*ends = 0;
- fprintf(out, "{\"metric-value\" : \"%s\"}", vals);
+ fprintf(out, "%s\"%s\" : \"%s\"", os->first ? "" : ", ", unit, vals);
+ os->first = false;
}

static void new_line_metric(struct perf_stat_config *config __maybe_unused,
@@ -561,7 +562,7 @@ static void print_metric_header(struct perf_stat_config *config,
unit = fixunit(tbuf, os->evsel, unit);

if (config->json_output)
- fprintf(os->fh, "{\"unit\" : \"%s\"}", unit);
+ return;
else if (config->csv_output)
fprintf(os->fh, "%s%s", unit, config->csv_sep);
else
@@ -821,6 +822,8 @@ static void print_counter_aggrdata(struct perf_stat_config *config,
run = aggr->counts.run;

if (!metric_only) {
+ if (config->json_output)
+ fputc('{', output);
if (os->prefix)
fprintf(output, "%s", os->prefix);
else if (config->summary && config->csv_output &&
@@ -844,9 +847,12 @@ static void print_metric_begin(struct perf_stat_config *config,
struct aggr_cpu_id id;
struct evsel *evsel;

+ os->first = true;
if (!config->metric_only)
return;

+ if (config->json_output)
+ fputc('{', config->output);
if (os->prefix)
fprintf(config->output, "%s", os->prefix);

@@ -855,7 +861,7 @@ static void print_metric_begin(struct perf_stat_config *config,
aggr = &evsel->stats->aggr[aggr_idx];
aggr_printout(config, evsel, id, aggr->nr);

- print_cgroup(config, os->cgrp);
+ print_cgroup(config, os->cgrp ? : evsel->cgrp);
}

static void print_metric_end(struct perf_stat_config *config)
@@ -863,6 +869,8 @@ static void print_metric_end(struct perf_stat_config *config)
if (!config->metric_only)
return;

+ if (config->json_output)
+ fputc('}', config->output);
fputc('\n', config->output);
}

@@ -1005,11 +1013,9 @@ static void print_metric_headers_csv(struct perf_stat_config *config,
fputs(aggr_header_csv[config->aggr_mode], config->output);
}

-static void print_metric_headers_json(struct perf_stat_config *config,
+static void print_metric_headers_json(struct perf_stat_config *config __maybe_unused,
bool no_indent __maybe_unused)
{
- if (config->interval)
- fputs("{\"unit\" : \"sec\"}", config->output);
}

static void print_metric_headers(struct perf_stat_config *config,
@@ -1049,7 +1055,9 @@ static void print_metric_headers(struct perf_stat_config *config,
&config->metric_events,
&rt_stat);
}
- fputc('\n', config->output);
+
+ if (!config->json_output)
+ fputc('\n', config->output);
}

static void prepare_interval(struct perf_stat_config *config,
@@ -1058,17 +1066,14 @@ static void prepare_interval(struct perf_stat_config *config,
if (config->iostat_run)
return;

- if (config->csv_output)
+ if (config->json_output)
+ scnprintf(prefix, len, "\"interval\" : %lu.%09lu, ",
+ (unsigned long) ts->tv_sec, ts->tv_nsec);
+ else if (config->csv_output)
scnprintf(prefix, len, "%lu.%09lu%s",
(unsigned long) ts->tv_sec, ts->tv_nsec, config->csv_sep);
- else if (!config->json_output)
- scnprintf(prefix, len, "%6lu.%09lu ",
- (unsigned long) ts->tv_sec, ts->tv_nsec);
- else if (!config->metric_only)
- scnprintf(prefix, len, "{\"interval\" : %lu.%09lu, ",
- (unsigned long) ts->tv_sec, ts->tv_nsec);
else
- scnprintf(prefix, len, "{\"interval\" : %lu.%09lu}",
+ scnprintf(prefix, len, "%6lu.%09lu ",
(unsigned long) ts->tv_sec, ts->tv_nsec);
}

@@ -1365,6 +1370,7 @@ void evlist__print_counters(struct evlist *evlist, struct perf_stat_config *conf
char buf[64];
struct outstate os = {
.fh = config->output,
+ .first = true,
};

if (config->iostat_run)
--
2.38.1.584.g0f3c55d4c2-goog


2022-11-24 00:14:34

by Ian Rogers

[permalink] [raw]
Subject: Re: [PATCH 13/15] perf stat: Fix JSON output in metric-only mode

On Wed, Nov 23, 2022 at 10:02 AM Namhyung Kim <[email protected]> wrote:
>
> It generated a broken JSON output when aggregation mode or cgroup is
> used with --metric-only option. Also get rid of the header line and
> make the output single line for each entry.
>
> It needs to know whether the current metric is the first one or not.
> So add 'first' field in the outstate and mark it false after printing.
>
> Before:
> # perf stat -a -j --metric-only true
> {"unit" : "GHz"}{"unit" : "insn per cycle"}{"unit" : "branch-misses of all branches"}
> {{"metric-value" : "0.797"}{"metric-value" : "1.65"}{"metric-value" : "0.89"}
> ^
>
> # perf stat -a -j --metric-only --per-socket true
> {"unit" : "GHz"}{"unit" : "insn per cycle"}{"unit" : "branch-misses of all branches"}
> {"socket" : "S0", "aggregate-number" : 8, {"metric-value" : "0.295"}{"metric-value" : "1.88"}{"metric-value" : "0.64"}
> ^
>
> After:
> # perf stat -a -j --metric-only true
> {"GHz" : "0.990", "insn per cycle" : "2.06", "branch-misses of all branches" : "0.59"}
>
> # perf stat -a -j --metric-only --per-socket true
> {"socket" : "S0", "aggregate-number" : 8, "GHz" : "0.439", "insn per cycle" : "2.14", "branch-misses of all branches" : "0.51"}
>
> Signed-off-by: Namhyung Kim <[email protected]>

Acked-by: Ian Rogers <[email protected]>

Thanks,
Ian

> ---
> tools/perf/util/stat-display.c | 42 +++++++++++++++++++---------------
> 1 file changed, 24 insertions(+), 18 deletions(-)
>
> diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c
> index 335627e8542d..43640115454c 100644
> --- a/tools/perf/util/stat-display.c
> +++ b/tools/perf/util/stat-display.c
> @@ -279,9 +279,6 @@ static void print_aggr_id_json(struct perf_stat_config *config,
> {
> FILE *output = config->output;
>
> - if (!config->interval)
> - fputc('{', output);
> -
> switch (config->aggr_mode) {
> case AGGR_CORE:
> fprintf(output, "\"core\" : \"S%d-D%d-C%d\", \"aggregate-number\" : %d, ",
> @@ -335,6 +332,7 @@ static void aggr_printout(struct perf_stat_config *config,
> struct outstate {
> FILE *fh;
> bool newline;
> + bool first;
> const char *prefix;
> int nfields;
> int nr;
> @@ -491,6 +489,7 @@ static void print_metric_only(struct perf_stat_config *config,
>
> color_snprintf(str, sizeof(str), color ?: "", fmt, val);
> fprintf(out, "%*s ", mlen, str);
> + os->first = false;
> }
>
> static void print_metric_only_csv(struct perf_stat_config *config __maybe_unused,
> @@ -512,6 +511,7 @@ static void print_metric_only_csv(struct perf_stat_config *config __maybe_unused
> ends++;
> *ends = 0;
> fprintf(out, "%s%s", vals, config->csv_sep);
> + os->first = false;
> }
>
> static void print_metric_only_json(struct perf_stat_config *config __maybe_unused,
> @@ -532,7 +532,8 @@ static void print_metric_only_json(struct perf_stat_config *config __maybe_unuse
> while (isdigit(*ends) || *ends == '.')
> ends++;
> *ends = 0;
> - fprintf(out, "{\"metric-value\" : \"%s\"}", vals);
> + fprintf(out, "%s\"%s\" : \"%s\"", os->first ? "" : ", ", unit, vals);
> + os->first = false;
> }
>
> static void new_line_metric(struct perf_stat_config *config __maybe_unused,
> @@ -561,7 +562,7 @@ static void print_metric_header(struct perf_stat_config *config,
> unit = fixunit(tbuf, os->evsel, unit);
>
> if (config->json_output)
> - fprintf(os->fh, "{\"unit\" : \"%s\"}", unit);
> + return;
> else if (config->csv_output)
> fprintf(os->fh, "%s%s", unit, config->csv_sep);
> else
> @@ -821,6 +822,8 @@ static void print_counter_aggrdata(struct perf_stat_config *config,
> run = aggr->counts.run;
>
> if (!metric_only) {
> + if (config->json_output)
> + fputc('{', output);
> if (os->prefix)
> fprintf(output, "%s", os->prefix);
> else if (config->summary && config->csv_output &&
> @@ -844,9 +847,12 @@ static void print_metric_begin(struct perf_stat_config *config,
> struct aggr_cpu_id id;
> struct evsel *evsel;
>
> + os->first = true;
> if (!config->metric_only)
> return;
>
> + if (config->json_output)
> + fputc('{', config->output);
> if (os->prefix)
> fprintf(config->output, "%s", os->prefix);
>
> @@ -855,7 +861,7 @@ static void print_metric_begin(struct perf_stat_config *config,
> aggr = &evsel->stats->aggr[aggr_idx];
> aggr_printout(config, evsel, id, aggr->nr);
>
> - print_cgroup(config, os->cgrp);
> + print_cgroup(config, os->cgrp ? : evsel->cgrp);
> }
>
> static void print_metric_end(struct perf_stat_config *config)
> @@ -863,6 +869,8 @@ static void print_metric_end(struct perf_stat_config *config)
> if (!config->metric_only)
> return;
>
> + if (config->json_output)
> + fputc('}', config->output);
> fputc('\n', config->output);
> }
>
> @@ -1005,11 +1013,9 @@ static void print_metric_headers_csv(struct perf_stat_config *config,
> fputs(aggr_header_csv[config->aggr_mode], config->output);
> }
>
> -static void print_metric_headers_json(struct perf_stat_config *config,
> +static void print_metric_headers_json(struct perf_stat_config *config __maybe_unused,
> bool no_indent __maybe_unused)
> {
> - if (config->interval)
> - fputs("{\"unit\" : \"sec\"}", config->output);
> }
>
> static void print_metric_headers(struct perf_stat_config *config,
> @@ -1049,7 +1055,9 @@ static void print_metric_headers(struct perf_stat_config *config,
> &config->metric_events,
> &rt_stat);
> }
> - fputc('\n', config->output);
> +
> + if (!config->json_output)
> + fputc('\n', config->output);
> }
>
> static void prepare_interval(struct perf_stat_config *config,
> @@ -1058,17 +1066,14 @@ static void prepare_interval(struct perf_stat_config *config,
> if (config->iostat_run)
> return;
>
> - if (config->csv_output)
> + if (config->json_output)
> + scnprintf(prefix, len, "\"interval\" : %lu.%09lu, ",
> + (unsigned long) ts->tv_sec, ts->tv_nsec);
> + else if (config->csv_output)
> scnprintf(prefix, len, "%lu.%09lu%s",
> (unsigned long) ts->tv_sec, ts->tv_nsec, config->csv_sep);
> - else if (!config->json_output)
> - scnprintf(prefix, len, "%6lu.%09lu ",
> - (unsigned long) ts->tv_sec, ts->tv_nsec);
> - else if (!config->metric_only)
> - scnprintf(prefix, len, "{\"interval\" : %lu.%09lu, ",
> - (unsigned long) ts->tv_sec, ts->tv_nsec);
> else
> - scnprintf(prefix, len, "{\"interval\" : %lu.%09lu}",
> + scnprintf(prefix, len, "%6lu.%09lu ",
> (unsigned long) ts->tv_sec, ts->tv_nsec);
> }
>
> @@ -1365,6 +1370,7 @@ void evlist__print_counters(struct evlist *evlist, struct perf_stat_config *conf
> char buf[64];
> struct outstate os = {
> .fh = config->output,
> + .first = true,
> };
>
> if (config->iostat_run)
> --
> 2.38.1.584.g0f3c55d4c2-goog
>

2022-12-02 18:21:14

by Namhyung Kim

[permalink] [raw]
Subject: Re: [PATCH 13/15] perf stat: Fix JSON output in metric-only mode

Hello,

On Thu, Dec 1, 2022 at 4:56 PM Wang, Weilin <[email protected]> wrote:
>
> Hi Namhyung,
>
>
>
> I encountered an issue with the metric json output, which I think might be related to this commit.
>
>
>
> This is one of the commands I tried:
>
>
>
> ./perf stat -M memory_bandwidth_total,memory_bandwidth_read,memory_bandwidth_write -a -j -- sleep 1
>
>
>
> Output before this commit:
>
> ====================================================
>
> {"counter-value" : "1117309.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.RD", "event-runtime" : 8017286783, "pcnt-running" : 100.00, "metric-value" : 124.961911, "metric-unit" : "MB/s memory_bandwidth_read"} {"metric-value" : 237.237504, "metric-unit" : "MB/s memory_bandwidth_total"} {"counter-value" : "1004052.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.WR", "event-runtime" : 8017286783, "pcnt-running" : 100.00, "metric-value" : 112.275593, "metric-unit" : "MB/s memory_bandwidth_write"} {"counter-value" : "1002140370.000000", "unit" : "ns", "event" : "duration_time", "event-runtime" : 1002140370, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "(null)"}
>
> ====================================================
>
>
>
> Output after this commit:
>
> ====================================================
>
> {"counter-value" : "1374098.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.RD", "event-runtime" : 8016491003, "pcnt-running" : 100.00, "metric-value" : 153.660738, "metric-unit" : "MB/s memory_bandwidth_read"} "metric-value" : 300.338968, "metric-unit" : "MB/s memory_bandwidth_total"} {"counter-value" : "1311710.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.WR", "event-runtime" : 8016491003, "pcnt-running" : 100.00, "metric-value" : 146.678229, "metric-unit" : "MB/s memory_bandwidth_write"} {"counter-value" : "1002037512.000000", "unit" : "ns", "event" : "duration_time", "event-runtime" : 1002037512, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "(null)"}
>
> ====================================================
>
>
>
> The second set of output is missing a "{" on the second line. Looks like it happens when I collect two related metrics together. Another example is:
>
>
>
> ./perf stat -M memory_bandwidth_total,memory_bandwidth_read,memory_bandwidth_write,L3_Cache_Fill_BW_1T,L3_Cache_Fill_BW -a -j -- sleep 1
>
>
>
> {"counter-value" : "944204.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.RD", "event-runtime" : 8033937053, "pcnt-running" : 100.00, "metric-value" : 105.369994, "metric-unit" : "MB/s memory_bandwidth_read"} "metric-value" : 210.592807, "metric-unit" : "MB/s memory_bandwidth_total"} {"counter-value" : "942679.000000", "unit" : "", "event" : "UNC_M_CAS_COUNT.WR", "event-runtime" : 8033937053, "pcnt-running" : 100.00, "metric-value" : 105.222813, "metric-unit" : "MB/s memory_bandwidth_write"} {"counter-value" : "1004471458.000000", "unit" : "ns", "event" : "duration_time", "event-runtime" : 1004471458, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "(null)"} {"counter-value" : "184675.000000", "unit" : "", "event" : "LONGEST_LAT_CACHE.MISS", "event-runtime" : 88387319917, "pcnt-running" : 100.00, "metric-value" : 0.011767, "metric-unit" : "L3_Cache_Fill_BW_1T"} "metric-value" : 0.011767, "metric-unit" : "L3_Cache_Fill_BW"} {"counter-value" : "1004471458.000000", "unit" : "ns", "event" : "duration_time", "event-runtime" : 1004471458, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "(null)"}

Thanks for your report. It seems it misses the open bracket when the metric
produces more than one values. I think new_line_json() should have it.
Will send the fix soon.

Thanks,
Namhyung