* [PATCH 0/2] perf test: Fix JSON linter
@ 2023-01-20 13:40 Michael Petlan
2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan
` (2 more replies)
0 siblings, 3 replies; 18+ messages in thread
From: Michael Petlan @ 2023-01-20 13:40 UTC (permalink / raw)
To: linux-perf-users, acme; +Cc: acme, qzhao, cjense
Hello all.
We have observed issues with the 'perf stat JSON output linter' testcase
on systems that allow topdown metrics.
=========================
1) The topdown metrics handling hardcodes printing more than one metric
per line (refer to util/stat-shadow.c):
if (retiring > 0.7 && heavy_ops > 0.1)
color = PERF_COLOR_GREEN;
print_metric(config, ctxp, color, "%8.1f%%", "Heavy Operations",
heavy_ops * 100.);
if (retiring > 0.7 && light_ops > 0.6)
color = PERF_COLOR_GREEN;
else
color = NULL;
print_metric(config, ctxp, color, "%8.1f%%", "Light Operations",
light_ops * 100.);
Thus, the test cannot rely on the fact that there will be only one
metric per line.
2) Since the JSON printing engine thinks that one and only one metric
is printed, it always closes the line by adding '}'. This is not true,
so I have fixed the comma printing and adjusted the engine to be
capable of printing 1-N metrics and then close the line.
=========================
On machines that don't support topdown, the problem can be shown by
doubling the following line in util/stat-shadow.c, so that the simple
'insn per cycle' metric is printed twice:
print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio);
The worst problem is that the JSON line is broken, such as:
... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit"
: "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ...
here ^^^^^
=========================
The first patch solves the JSON output correctness, the second tries
to adjust the testcase to some extent, so that it should work on the
topdown-capable machines.
However, it's highly possible that the testcase will have to be fixed
or maybe rewritten in future. First, it has quite naive evaluation of
what's expected/correct/etc. Second, it does no JSON format validation
at all. As a linter it should do so though.
***
For further discussion: What about removing the check for number of
expected elements in the line and just check for the keywords, such
as "metric-value", "counter-value", "event", etc. and for some values
that should be numeric. And, do proper JSON format sanity check?
Thank you for inputs!
Michael
Michael Petlan (2):
perf stat: Fix JSON metric printout for multiple metrics per line
perf test: Fix JSON format linter test checks
.../tests/shell/lib/perf_json_output_lint.py | 16 +++++------
tools/perf/util/stat-display.c | 28 +++++++++++--------
2 files changed, 24 insertions(+), 20 deletions(-)
--
2.18.4
^ permalink raw reply [flat|nested] 18+ messages in thread* [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line 2023-01-20 13:40 [PATCH 0/2] perf test: Fix JSON linter Michael Petlan @ 2023-01-20 13:40 ` Michael Petlan 2023-01-23 6:31 ` Namhyung Kim 2023-05-22 12:11 ` Michael Petlan 2023-01-20 13:40 ` [PATCH 2/2] perf test: Fix JSON format linter test checks Michael Petlan 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers 2 siblings, 2 replies; 18+ messages in thread From: Michael Petlan @ 2023-01-20 13:40 UTC (permalink / raw) To: linux-perf-users, acme; +Cc: acme, qzhao, cjense JSON printing engine used to always print metric (even when there should be none and other engines (std, csv) would not print it) and the metric used to always close the line by printing a closing curly bracket. This caused invalid JSON output being generated for top-down metrics, when multiple metrics are printed on a single line, so the broken output might have looked like: ... "metric-value" : 15.564203, "metric-unit" : \ "Memory Bound"}"metric-value" : 14.007787, "metric-unit" : "Core Bound"} To fix it, print always the separating comma BEFORE the key:value pairs and close the line outside of the JSON metric printing routine. Fixes: df936cadfb58 ("perf stat: Add JSON output option") Signed-off-by: Michael Petlan <mpetlan@redhat.com> --- tools/perf/util/stat-display.c | 28 ++++++++++++++++------------ 1 file changed, 16 insertions(+), 12 deletions(-) diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c index 8bd8b0142630..8f80f6b566d0 100644 --- a/tools/perf/util/stat-display.c +++ b/tools/perf/util/stat-display.c @@ -86,7 +86,7 @@ static void print_running_json(struct perf_stat_config *config, u64 run, u64 ena if (run != ena) enabled_percent = 100 * run / ena; - fprintf(config->output, "\"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f, ", + fprintf(config->output, ", \"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f", run, enabled_percent); } @@ -121,7 +121,7 @@ static void print_noise_pct_csv(struct perf_stat_config *config, static void print_noise_pct_json(struct perf_stat_config *config, double pct) { - fprintf(config->output, "\"variance\" : %.2f, ", pct); + fprintf(config->output, ", \"variance\" : %.2f", pct); } static void print_noise_pct(struct perf_stat_config *config, @@ -165,7 +165,7 @@ static void print_cgroup_csv(struct perf_stat_config *config, const char *cgrp_n static void print_cgroup_json(struct perf_stat_config *config, const char *cgrp_name) { - fprintf(config->output, "\"cgroup\" : \"%s\", ", cgrp_name); + fprintf(config->output, ", \"cgroup\" : \"%s\"", cgrp_name); } static void print_cgroup(struct perf_stat_config *config, struct cgroup *cgrp) @@ -431,10 +431,11 @@ static void print_metric_json(struct perf_stat_config *config __maybe_unused, struct outstate *os = ctx; FILE *out = os->fh; - fprintf(out, "\"metric-value\" : %f, ", val); - fprintf(out, "\"metric-unit\" : \"%s\"", unit); - if (!config->metric_only) - fprintf(out, "}"); + if (unit == NULL || fmt == NULL) + return; + + fprintf(out, ", \"metric-value\" : %f", val); + fprintf(out, ", \"metric-unit\" : \"%s\"", unit); } static void new_line_json(struct perf_stat_config *config, void *ctx) @@ -623,14 +624,14 @@ static void print_counter_value_json(struct perf_stat_config *config, const char *bad_count = evsel->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED; if (ok) - fprintf(output, "\"counter-value\" : \"%f\", ", avg); + fprintf(output, "\"counter-value\" : \"%f\"", avg); else - fprintf(output, "\"counter-value\" : \"%s\", ", bad_count); + fprintf(output, "\"counter-value\" : \"%s\"", bad_count); if (evsel->unit) - fprintf(output, "\"unit\" : \"%s\", ", evsel->unit); + fprintf(output, ", \"unit\" : \"%s\"", evsel->unit); - fprintf(output, "\"event\" : \"%s\", ", evsel__name(evsel)); + fprintf(output, ", \"event\" : \"%s\"", evsel__name(evsel)); } static void print_counter_value(struct perf_stat_config *config, @@ -835,8 +836,11 @@ static void print_counter_aggrdata(struct perf_stat_config *config, printout(config, os, uval, run, ena, avg, s); - if (!metric_only) + if (!metric_only) { + if (config->json_output) + fputc('}', output); fputc('\n', output); + } } static void print_metric_begin(struct perf_stat_config *config, -- 2.18.4 ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line 2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan @ 2023-01-23 6:31 ` Namhyung Kim 2023-05-22 12:11 ` Michael Petlan 1 sibling, 0 replies; 18+ messages in thread From: Namhyung Kim @ 2023-01-23 6:31 UTC (permalink / raw) To: Michael Petlan; +Cc: linux-perf-users, acme, acme, qzhao, cjense Hello Michael, On Fri, Jan 20, 2023 at 5:47 AM Michael Petlan <mpetlan@redhat.com> wrote: > > JSON printing engine used to always print metric (even when there should > be none and other engines (std, csv) would not print it) and the metric > used to always close the line by printing a closing curly bracket. > > This caused invalid JSON output being generated for top-down metrics, > when multiple metrics are printed on a single line, so the broken output > might have looked like: > > ... "metric-value" : 15.564203, "metric-unit" : \ > "Memory Bound"}"metric-value" : 14.007787, "metric-unit" : "Core Bound"} > > To fix it, print always the separating comma BEFORE the key:value pairs > and close the line outside of the JSON metric printing routine. > > Fixes: df936cadfb58 ("perf stat: Add JSON output option") > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> Acked-by: Namhyung Kim <namhyung@kernel.org> Thanks for the fix, a nitpick below.. > --- > tools/perf/util/stat-display.c | 28 ++++++++++++++++------------ > 1 file changed, 16 insertions(+), 12 deletions(-) > > diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c > index 8bd8b0142630..8f80f6b566d0 100644 > --- a/tools/perf/util/stat-display.c > +++ b/tools/perf/util/stat-display.c > @@ -86,7 +86,7 @@ static void print_running_json(struct perf_stat_config *config, u64 run, u64 ena > > if (run != ena) > enabled_percent = 100 * run / ena; > - fprintf(config->output, "\"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f, ", > + fprintf(config->output, ", \"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f", > run, enabled_percent); > } > > @@ -121,7 +121,7 @@ static void print_noise_pct_csv(struct perf_stat_config *config, > static void print_noise_pct_json(struct perf_stat_config *config, > double pct) > { > - fprintf(config->output, "\"variance\" : %.2f, ", pct); > + fprintf(config->output, ", \"variance\" : %.2f", pct); > } > > static void print_noise_pct(struct perf_stat_config *config, > @@ -165,7 +165,7 @@ static void print_cgroup_csv(struct perf_stat_config *config, const char *cgrp_n > > static void print_cgroup_json(struct perf_stat_config *config, const char *cgrp_name) > { > - fprintf(config->output, "\"cgroup\" : \"%s\", ", cgrp_name); > + fprintf(config->output, ", \"cgroup\" : \"%s\"", cgrp_name); > } > > static void print_cgroup(struct perf_stat_config *config, struct cgroup *cgrp) > @@ -431,10 +431,11 @@ static void print_metric_json(struct perf_stat_config *config __maybe_unused, > struct outstate *os = ctx; > FILE *out = os->fh; > > - fprintf(out, "\"metric-value\" : %f, ", val); > - fprintf(out, "\"metric-unit\" : \"%s\"", unit); > - if (!config->metric_only) > - fprintf(out, "}"); > + if (unit == NULL || fmt == NULL) > + return; This seems like a separate fix. Thanks, Namhyung > + > + fprintf(out, ", \"metric-value\" : %f", val); > + fprintf(out, ", \"metric-unit\" : \"%s\"", unit); > } > > static void new_line_json(struct perf_stat_config *config, void *ctx) > @@ -623,14 +624,14 @@ static void print_counter_value_json(struct perf_stat_config *config, > const char *bad_count = evsel->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED; > > if (ok) > - fprintf(output, "\"counter-value\" : \"%f\", ", avg); > + fprintf(output, "\"counter-value\" : \"%f\"", avg); > else > - fprintf(output, "\"counter-value\" : \"%s\", ", bad_count); > + fprintf(output, "\"counter-value\" : \"%s\"", bad_count); > > if (evsel->unit) > - fprintf(output, "\"unit\" : \"%s\", ", evsel->unit); > + fprintf(output, ", \"unit\" : \"%s\"", evsel->unit); > > - fprintf(output, "\"event\" : \"%s\", ", evsel__name(evsel)); > + fprintf(output, ", \"event\" : \"%s\"", evsel__name(evsel)); > } > > static void print_counter_value(struct perf_stat_config *config, > @@ -835,8 +836,11 @@ static void print_counter_aggrdata(struct perf_stat_config *config, > > printout(config, os, uval, run, ena, avg, s); > > - if (!metric_only) > + if (!metric_only) { > + if (config->json_output) > + fputc('}', output); > fputc('\n', output); > + } > } > > static void print_metric_begin(struct perf_stat_config *config, > -- > 2.18.4 > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line 2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan 2023-01-23 6:31 ` Namhyung Kim @ 2023-05-22 12:11 ` Michael Petlan 2023-06-06 11:16 ` Michael Petlan 1 sibling, 1 reply; 18+ messages in thread From: Michael Petlan @ 2023-05-22 12:11 UTC (permalink / raw) To: acme; +Cc: linux-perf-users, acme, qzhao, cjense, irogers Hello Ian and Arnaldo, I've recently got back to the JSON test failures. In January, I post two patches within a patchset. I see that Ian has updated the testcase code, so the second patch is probably no more needed. However I don't see this one applied upstream yet, although it seemed on the list, it had got some acks. Has it been forgotten somehow? To remind, since the JSON printer engine wasn't ready to print multiple metrics per line, the JSON output got screwed up in that situation. The situation happened on some SPR CPUs, where Top-Down metrics are supported. The patch below fixes the printer to handle this situation correctly. I remember someone saying that the whole printer engine needs to be refactored some day, but I'd think that before that happens, it'd be nice to have it fixed... What do you think? Regards, Michael On Fri, 20 Jan 2023, Michael Petlan wrote: > JSON printing engine used to always print metric (even when there should > be none and other engines (std, csv) would not print it) and the metric > used to always close the line by printing a closing curly bracket. > > This caused invalid JSON output being generated for top-down metrics, > when multiple metrics are printed on a single line, so the broken output > might have looked like: > > ... "metric-value" : 15.564203, "metric-unit" : \ > "Memory Bound"}"metric-value" : 14.007787, "metric-unit" : "Core Bound"} > > To fix it, print always the separating comma BEFORE the key:value pairs > and close the line outside of the JSON metric printing routine. > > Fixes: df936cadfb58 ("perf stat: Add JSON output option") > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> > --- > tools/perf/util/stat-display.c | 28 ++++++++++++++++------------ > 1 file changed, 16 insertions(+), 12 deletions(-) > > diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c > index 8bd8b0142630..8f80f6b566d0 100644 > --- a/tools/perf/util/stat-display.c > +++ b/tools/perf/util/stat-display.c > @@ -86,7 +86,7 @@ static void print_running_json(struct perf_stat_config *config, u64 run, u64 ena > > if (run != ena) > enabled_percent = 100 * run / ena; > - fprintf(config->output, "\"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f, ", > + fprintf(config->output, ", \"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f", > run, enabled_percent); > } > > @@ -121,7 +121,7 @@ static void print_noise_pct_csv(struct perf_stat_config *config, > static void print_noise_pct_json(struct perf_stat_config *config, > double pct) > { > - fprintf(config->output, "\"variance\" : %.2f, ", pct); > + fprintf(config->output, ", \"variance\" : %.2f", pct); > } > > static void print_noise_pct(struct perf_stat_config *config, > @@ -165,7 +165,7 @@ static void print_cgroup_csv(struct perf_stat_config *config, const char *cgrp_n > > static void print_cgroup_json(struct perf_stat_config *config, const char *cgrp_name) > { > - fprintf(config->output, "\"cgroup\" : \"%s\", ", cgrp_name); > + fprintf(config->output, ", \"cgroup\" : \"%s\"", cgrp_name); > } > > static void print_cgroup(struct perf_stat_config *config, struct cgroup *cgrp) > @@ -431,10 +431,11 @@ static void print_metric_json(struct perf_stat_config *config __maybe_unused, > struct outstate *os = ctx; > FILE *out = os->fh; > > - fprintf(out, "\"metric-value\" : %f, ", val); > - fprintf(out, "\"metric-unit\" : \"%s\"", unit); > - if (!config->metric_only) > - fprintf(out, "}"); > + if (unit == NULL || fmt == NULL) > + return; > + > + fprintf(out, ", \"metric-value\" : %f", val); > + fprintf(out, ", \"metric-unit\" : \"%s\"", unit); > } > > static void new_line_json(struct perf_stat_config *config, void *ctx) > @@ -623,14 +624,14 @@ static void print_counter_value_json(struct perf_stat_config *config, > const char *bad_count = evsel->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED; > > if (ok) > - fprintf(output, "\"counter-value\" : \"%f\", ", avg); > + fprintf(output, "\"counter-value\" : \"%f\"", avg); > else > - fprintf(output, "\"counter-value\" : \"%s\", ", bad_count); > + fprintf(output, "\"counter-value\" : \"%s\"", bad_count); > > if (evsel->unit) > - fprintf(output, "\"unit\" : \"%s\", ", evsel->unit); > + fprintf(output, ", \"unit\" : \"%s\"", evsel->unit); > > - fprintf(output, "\"event\" : \"%s\", ", evsel__name(evsel)); > + fprintf(output, ", \"event\" : \"%s\"", evsel__name(evsel)); > } > > static void print_counter_value(struct perf_stat_config *config, > @@ -835,8 +836,11 @@ static void print_counter_aggrdata(struct perf_stat_config *config, > > printout(config, os, uval, run, ena, avg, s); > > - if (!metric_only) > + if (!metric_only) { > + if (config->json_output) > + fputc('}', output); > fputc('\n', output); > + } > } > > static void print_metric_begin(struct perf_stat_config *config, > -- > 2.18.4 > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line 2023-05-22 12:11 ` Michael Petlan @ 2023-06-06 11:16 ` Michael Petlan 0 siblings, 0 replies; 18+ messages in thread From: Michael Petlan @ 2023-06-06 11:16 UTC (permalink / raw) To: acme; +Cc: linux-perf-users, acme, qzhao, cjense, irogers Gently ping... On Mon, 22 May 2023, Michael Petlan wrote: > Hello Ian and Arnaldo, > > I've recently got back to the JSON test failures. In January, I post two > patches within a patchset. I see that Ian has updated the testcase code, > so the second patch is probably no more needed. However I don't see this > one applied upstream yet, although it seemed on the list, it had got some > acks. Has it been forgotten somehow? > > To remind, since the JSON printer engine wasn't ready to print multiple > metrics per line, the JSON output got screwed up in that situation. The > situation happened on some SPR CPUs, where Top-Down metrics are supported. > > The patch below fixes the printer to handle this situation correctly. > > I remember someone saying that the whole printer engine needs to be > refactored some day, but I'd think that before that happens, it'd be > nice to have it fixed... > > What do you think? > > Regards, > Michael > > On Fri, 20 Jan 2023, Michael Petlan wrote: > > JSON printing engine used to always print metric (even when there should > > be none and other engines (std, csv) would not print it) and the metric > > used to always close the line by printing a closing curly bracket. > > > > This caused invalid JSON output being generated for top-down metrics, > > when multiple metrics are printed on a single line, so the broken output > > might have looked like: > > > > ... "metric-value" : 15.564203, "metric-unit" : \ > > "Memory Bound"}"metric-value" : 14.007787, "metric-unit" : "Core Bound"} > > > > To fix it, print always the separating comma BEFORE the key:value pairs > > and close the line outside of the JSON metric printing routine. > > > > Fixes: df936cadfb58 ("perf stat: Add JSON output option") > > > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> > > --- > > tools/perf/util/stat-display.c | 28 ++++++++++++++++------------ > > 1 file changed, 16 insertions(+), 12 deletions(-) > > > > diff --git a/tools/perf/util/stat-display.c b/tools/perf/util/stat-display.c > > index 8bd8b0142630..8f80f6b566d0 100644 > > --- a/tools/perf/util/stat-display.c > > +++ b/tools/perf/util/stat-display.c > > @@ -86,7 +86,7 @@ static void print_running_json(struct perf_stat_config *config, u64 run, u64 ena > > > > if (run != ena) > > enabled_percent = 100 * run / ena; > > - fprintf(config->output, "\"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f, ", > > + fprintf(config->output, ", \"event-runtime\" : %" PRIu64 ", \"pcnt-running\" : %.2f", > > run, enabled_percent); > > } > > > > @@ -121,7 +121,7 @@ static void print_noise_pct_csv(struct perf_stat_config *config, > > static void print_noise_pct_json(struct perf_stat_config *config, > > double pct) > > { > > - fprintf(config->output, "\"variance\" : %.2f, ", pct); > > + fprintf(config->output, ", \"variance\" : %.2f", pct); > > } > > > > static void print_noise_pct(struct perf_stat_config *config, > > @@ -165,7 +165,7 @@ static void print_cgroup_csv(struct perf_stat_config *config, const char *cgrp_n > > > > static void print_cgroup_json(struct perf_stat_config *config, const char *cgrp_name) > > { > > - fprintf(config->output, "\"cgroup\" : \"%s\", ", cgrp_name); > > + fprintf(config->output, ", \"cgroup\" : \"%s\"", cgrp_name); > > } > > > > static void print_cgroup(struct perf_stat_config *config, struct cgroup *cgrp) > > @@ -431,10 +431,11 @@ static void print_metric_json(struct perf_stat_config *config __maybe_unused, > > struct outstate *os = ctx; > > FILE *out = os->fh; > > > > - fprintf(out, "\"metric-value\" : %f, ", val); > > - fprintf(out, "\"metric-unit\" : \"%s\"", unit); > > - if (!config->metric_only) > > - fprintf(out, "}"); > > + if (unit == NULL || fmt == NULL) > > + return; > > + > > + fprintf(out, ", \"metric-value\" : %f", val); > > + fprintf(out, ", \"metric-unit\" : \"%s\"", unit); > > } > > > > static void new_line_json(struct perf_stat_config *config, void *ctx) > > @@ -623,14 +624,14 @@ static void print_counter_value_json(struct perf_stat_config *config, > > const char *bad_count = evsel->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED; > > > > if (ok) > > - fprintf(output, "\"counter-value\" : \"%f\", ", avg); > > + fprintf(output, "\"counter-value\" : \"%f\"", avg); > > else > > - fprintf(output, "\"counter-value\" : \"%s\", ", bad_count); > > + fprintf(output, "\"counter-value\" : \"%s\"", bad_count); > > > > if (evsel->unit) > > - fprintf(output, "\"unit\" : \"%s\", ", evsel->unit); > > + fprintf(output, ", \"unit\" : \"%s\"", evsel->unit); > > > > - fprintf(output, "\"event\" : \"%s\", ", evsel__name(evsel)); > > + fprintf(output, ", \"event\" : \"%s\"", evsel__name(evsel)); > > } > > > > static void print_counter_value(struct perf_stat_config *config, > > @@ -835,8 +836,11 @@ static void print_counter_aggrdata(struct perf_stat_config *config, > > > > printout(config, os, uval, run, ena, avg, s); > > > > - if (!metric_only) > > + if (!metric_only) { > > + if (config->json_output) > > + fputc('}', output); > > fputc('\n', output); > > + } > > } > > > > static void print_metric_begin(struct perf_stat_config *config, > > -- > > 2.18.4 > > > > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-20 13:40 [PATCH 0/2] perf test: Fix JSON linter Michael Petlan 2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan @ 2023-01-20 13:40 ` Michael Petlan 2023-01-23 6:36 ` Namhyung Kim 2023-01-27 12:26 ` Arnaldo Carvalho de Melo 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers 2 siblings, 2 replies; 18+ messages in thread From: Michael Petlan @ 2023-01-20 13:40 UTC (permalink / raw) To: linux-perf-users, acme; +Cc: acme, qzhao, cjense The test fails on CPUs with topdown metrics, where it is common to print two metrics per line. Since these are included in default event set for `perf stat -- something`, it causes the "no args" subtest to fail due to unexpected member count. We need to accept 7 or 9 members in that case. Coming to that, counting commas in the JSON line and consider it a number of elements is incorrect and misleading. There should be +1 element than the count of commas, while also, commas can potentially appear in the event names. Count " : " substrings rather, since these better fit to what should be actually counted. Fixes: 0c343af2a2f8 ("perf test: JSON format checking") Signed-off-by: Michael Petlan <mpetlan@redhat.com> --- .../tests/shell/lib/perf_json_output_lint.py | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/tools/perf/tests/shell/lib/perf_json_output_lint.py b/tools/perf/tests/shell/lib/perf_json_output_lint.py index d90f8d102eb9..4f1bbb3f07ec 100644 --- a/tools/perf/tests/shell/lib/perf_json_output_lint.py +++ b/tools/perf/tests/shell/lib/perf_json_output_lint.py @@ -40,17 +40,17 @@ def is_counter_value(num): return isfloat(num) or num == '<not counted>' or num == '<not supported>' def check_json_output(expected_items): - if expected_items != -1: + if expected_items: for line in Lines: if 'failed' not in line: count = 0 - count = line.count(',') - if count != expected_items and count >= 1 and count <= 3 and 'metric-value' in line: + count = line.count(' : ') + if count not in expected_items and count >= 2 and count <= 4 and 'metric-value' in line: # Events that generate >1 metric may have isolated metric # values and possibly other prefixes like interval, core and # aggregate-number. continue - if count != expected_items: + if count not in expected_items: raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' f' in \'{line}\'') checks = { @@ -82,14 +82,14 @@ def check_json_output(expected_items): try: if args.no_args or args.system_wide or args.event: - expected_items = 6 + expected_items = [7, 9] elif args.interval or args.per_thread or args.system_wide_no_aggr: - expected_items = 7 + expected_items = [8, 10] elif args.per_core or args.per_socket or args.per_node or args.per_die: - expected_items = 8 + expected_items = [9, 11] else: # If no option is specified, don't check the number of items. - expected_items = -1 + expected_items = [] check_json_output(expected_items) except: print('Test failed for input:\n' + '\n'.join(Lines)) -- 2.18.4 ^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-20 13:40 ` [PATCH 2/2] perf test: Fix JSON format linter test checks Michael Petlan @ 2023-01-23 6:36 ` Namhyung Kim 2023-01-24 16:49 ` Michael Petlan 2023-01-27 12:26 ` Arnaldo Carvalho de Melo 1 sibling, 1 reply; 18+ messages in thread From: Namhyung Kim @ 2023-01-23 6:36 UTC (permalink / raw) To: Michael Petlan; +Cc: linux-perf-users, acme, acme, qzhao, cjense On Fri, Jan 20, 2023 at 6:00 AM Michael Petlan <mpetlan@redhat.com> wrote: > > The test fails on CPUs with topdown metrics, where it is common to print > two metrics per line. Since these are included in default event set for > `perf stat -- something`, it causes the "no args" subtest to fail due to > unexpected member count. We need to accept 7 or 9 members in that case. > > Coming to that, counting commas in the JSON line and consider it a number > of elements is incorrect and misleading. There should be +1 element than > the count of commas, while also, commas can potentially appear in the > event names. Count " : " substrings rather, since these better fit to > what should be actually counted. I'm also curious if ":" could appear in the event/metric names. Probably more chances to have ":" than "," in the name, no? Thanks, Namhyung > > Fixes: 0c343af2a2f8 ("perf test: JSON format checking") > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> > --- > .../tests/shell/lib/perf_json_output_lint.py | 16 ++++++++-------- > 1 file changed, 8 insertions(+), 8 deletions(-) > > diff --git a/tools/perf/tests/shell/lib/perf_json_output_lint.py b/tools/perf/tests/shell/lib/perf_json_output_lint.py > index d90f8d102eb9..4f1bbb3f07ec 100644 > --- a/tools/perf/tests/shell/lib/perf_json_output_lint.py > +++ b/tools/perf/tests/shell/lib/perf_json_output_lint.py > @@ -40,17 +40,17 @@ def is_counter_value(num): > return isfloat(num) or num == '<not counted>' or num == '<not supported>' > > def check_json_output(expected_items): > - if expected_items != -1: > + if expected_items: > for line in Lines: > if 'failed' not in line: > count = 0 > - count = line.count(',') > - if count != expected_items and count >= 1 and count <= 3 and 'metric-value' in line: > + count = line.count(' : ') > + if count not in expected_items and count >= 2 and count <= 4 and 'metric-value' in line: > # Events that generate >1 metric may have isolated metric > # values and possibly other prefixes like interval, core and > # aggregate-number. > continue > - if count != expected_items: > + if count not in expected_items: > raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' > f' in \'{line}\'') > checks = { > @@ -82,14 +82,14 @@ def check_json_output(expected_items): > > try: > if args.no_args or args.system_wide or args.event: > - expected_items = 6 > + expected_items = [7, 9] > elif args.interval or args.per_thread or args.system_wide_no_aggr: > - expected_items = 7 > + expected_items = [8, 10] > elif args.per_core or args.per_socket or args.per_node or args.per_die: > - expected_items = 8 > + expected_items = [9, 11] > else: > # If no option is specified, don't check the number of items. > - expected_items = -1 > + expected_items = [] > check_json_output(expected_items) > except: > print('Test failed for input:\n' + '\n'.join(Lines)) > -- > 2.18.4 > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-23 6:36 ` Namhyung Kim @ 2023-01-24 16:49 ` Michael Petlan 2023-01-24 17:26 ` Namhyung Kim 0 siblings, 1 reply; 18+ messages in thread From: Michael Petlan @ 2023-01-24 16:49 UTC (permalink / raw) To: Namhyung Kim; +Cc: linux-perf-users, acme, acme, qzhao, cjense On Sun, 22 Jan 2023, Namhyung Kim wrote: > On Fri, Jan 20, 2023 at 6:00 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > The test fails on CPUs with topdown metrics, where it is common to print > > two metrics per line. Since these are included in default event set for > > `perf stat -- something`, it causes the "no args" subtest to fail due to > > unexpected member count. We need to accept 7 or 9 members in that case. > > > > Coming to that, counting commas in the JSON line and consider it a number > > of elements is incorrect and misleading. There should be +1 element than > > the count of commas, while also, commas can potentially appear in the > > event names. Count " : " substrings rather, since these better fit to > > what should be actually counted. > > I'm also curious if ":" could appear in the event/metric names. > Probably more chances to have ":" than "," in the name, no? Yes, ':' can appear in the event names, but not " : " (with the spaces around). Michael > > Thanks, > Namhyung > > > > > > Fixes: 0c343af2a2f8 ("perf test: JSON format checking") > > > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> > > --- > > .../tests/shell/lib/perf_json_output_lint.py | 16 ++++++++-------- > > 1 file changed, 8 insertions(+), 8 deletions(-) > > > > diff --git a/tools/perf/tests/shell/lib/perf_json_output_lint.py b/tools/perf/tests/shell/lib/perf_json_output_lint.py > > index d90f8d102eb9..4f1bbb3f07ec 100644 > > --- a/tools/perf/tests/shell/lib/perf_json_output_lint.py > > +++ b/tools/perf/tests/shell/lib/perf_json_output_lint.py > > @@ -40,17 +40,17 @@ def is_counter_value(num): > > return isfloat(num) or num == '<not counted>' or num == '<not supported>' > > > > def check_json_output(expected_items): > > - if expected_items != -1: > > + if expected_items: > > for line in Lines: > > if 'failed' not in line: > > count = 0 > > - count = line.count(',') > > - if count != expected_items and count >= 1 and count <= 3 and 'metric-value' in line: > > + count = line.count(' : ') > > + if count not in expected_items and count >= 2 and count <= 4 and 'metric-value' in line: > > # Events that generate >1 metric may have isolated metric > > # values and possibly other prefixes like interval, core and > > # aggregate-number. > > continue > > - if count != expected_items: > > + if count not in expected_items: > > raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' > > f' in \'{line}\'') > > checks = { > > @@ -82,14 +82,14 @@ def check_json_output(expected_items): > > > > try: > > if args.no_args or args.system_wide or args.event: > > - expected_items = 6 > > + expected_items = [7, 9] > > elif args.interval or args.per_thread or args.system_wide_no_aggr: > > - expected_items = 7 > > + expected_items = [8, 10] > > elif args.per_core or args.per_socket or args.per_node or args.per_die: > > - expected_items = 8 > > + expected_items = [9, 11] > > else: > > # If no option is specified, don't check the number of items. > > - expected_items = -1 > > + expected_items = [] > > check_json_output(expected_items) > > except: > > print('Test failed for input:\n' + '\n'.join(Lines)) > > -- > > 2.18.4 > > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-24 16:49 ` Michael Petlan @ 2023-01-24 17:26 ` Namhyung Kim 0 siblings, 0 replies; 18+ messages in thread From: Namhyung Kim @ 2023-01-24 17:26 UTC (permalink / raw) To: Michael Petlan; +Cc: linux-perf-users, acme, acme, qzhao On Tue, Jan 24, 2023 at 8:49 AM Michael Petlan <mpetlan@redhat.com> wrote: > > On Sun, 22 Jan 2023, Namhyung Kim wrote: > > On Fri, Jan 20, 2023 at 6:00 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > > > The test fails on CPUs with topdown metrics, where it is common to print > > > two metrics per line. Since these are included in default event set for > > > `perf stat -- something`, it causes the "no args" subtest to fail due to > > > unexpected member count. We need to accept 7 or 9 members in that case. > > > > > > Coming to that, counting commas in the JSON line and consider it a number > > > of elements is incorrect and misleading. There should be +1 element than > > > the count of commas, while also, commas can potentially appear in the > > > event names. Count " : " substrings rather, since these better fit to > > > what should be actually counted. > > > > I'm also curious if ":" could appear in the event/metric names. > > Probably more chances to have ":" than "," in the name, no? > > Yes, ':' can appear in the event names, but not " : " (with the spaces > around). Ah, ok. Missed the whitespaces. :) Thanks, Namhyung ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-20 13:40 ` [PATCH 2/2] perf test: Fix JSON format linter test checks Michael Petlan 2023-01-23 6:36 ` Namhyung Kim @ 2023-01-27 12:26 ` Arnaldo Carvalho de Melo 2023-01-27 12:30 ` Arnaldo Carvalho de Melo 1 sibling, 1 reply; 18+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-01-27 12:26 UTC (permalink / raw) To: Michael Petlan Cc: linux-perf-users, acme, qzhao, cjense, Ian Rogers, Linux Kernel Mailing List, Namhyung Kim, Jiri Olsa, Adrian Hunter Em Fri, Jan 20, 2023 at 02:40:39PM +0100, Michael Petlan escreveu: > The test fails on CPUs with topdown metrics, where it is common to print > two metrics per line. Since these are included in default event set for > `perf stat -- something`, it causes the "no args" subtest to fail due to > unexpected member count. We need to accept 7 or 9 members in that case. > > Coming to that, counting commas in the JSON line and consider it a number > of elements is incorrect and misleading. There should be +1 element than > the count of commas, while also, commas can potentially appear in the > event names. Count " : " substrings rather, since these better fit to > what should be actually counted. Before I apply this first patch I can run, as root, the 'perf test' JSON lint 100 times without problems: [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done 1 98: perf stat JSON output linter : Ok 2 98: perf stat JSON output linter : Ok 3 98: perf stat JSON output linter : Ok 4 98: perf stat JSON output linter : Ok <SNIP> 96 98: perf stat JSON output linter : Ok 97 98: perf stat JSON output linter : Ok 98 98: perf stat JSON output linter : Ok 99 98: perf stat JSON output linter : Ok 100 98: perf stat JSON output linter : Ok [root@quaco ~]# After applying it it fails seemingly randomly, I'll remove both patches from my tmp.perf/core branch and investigate. [acme@quaco perf]$ git log --oneline -1 fdafd42aac3629db (HEAD) perf stat: Fix JSON metric printout for multiple metrics per line [acme@quaco perf]$ perf -v perf version 6.2.rc5.gfdafd42aac36 [acme@quaco perf]$ [root@quaco ~]# perf -v perf version 6.2.rc5.gfdafd42aac36 [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done [root@quaco ~]# perf -v perf version 6.2.rc5.gfdafd42aac36 [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done 1 98: perf stat JSON output linter : Ok 2 98: perf stat JSON output linter : Ok 3 98: perf stat JSON output linter : FAILED! 4 98: perf stat JSON output linter : Ok 5 98: perf stat JSON output linter : Ok 6 98: perf stat JSON output linter : Ok 7 98: perf stat JSON output linter : FAILED! 8 98: perf stat JSON output linter : Ok 9 98: perf stat JSON output linter : Ok 10 98: perf stat JSON output linter : Ok 11 98: perf stat JSON output linter : Ok 12 98: perf stat JSON output linter : Ok 13 98: perf stat JSON output linter : Ok 14 98: perf stat JSON output linter : Ok 15 98: perf stat JSON output linter : Ok 16 98: perf stat JSON output linter : FAILED! 17 98: perf stat JSON output linter : Ok 18 98: perf stat JSON output linter : Ok 19 98: perf stat JSON output linter : Ok 20 98: perf stat JSON output linter : FAILED! 21 98: perf stat JSON output linter : Ok 22 98: perf stat JSON output linter : Ok 23 98: perf stat JSON output linter : FAILED! 24 98: perf stat JSON output linter : Ok 25 98: perf stat JSON output linter : Ok 26 98: perf stat JSON output linter : Ok 27 98: perf stat JSON output linter : Ok 28 98: perf stat JSON output linter : FAILED! 29 98: perf stat JSON output linter : Ok 30 98: perf stat JSON output linter : Ok 31 98: perf stat JSON output linter : FAILED! 32 98: perf stat JSON output linter : FAILED! 33 98: perf stat JSON output linter : FAILED! 34 98: perf stat JSON output linter : Ok 35 98: perf stat JSON output linter : Ok 36 98: perf stat JSON output linter : Ok 37 98: perf stat JSON output linter : Ok 38 98: perf stat JSON output linter : FAILED! 39 98: perf stat JSON output linter : FAILED! 40 98: perf stat JSON output linter : FAILED! 41 98: perf stat JSON output linter : Ok 42 98: perf stat JSON output linter : Ok 43 98: perf stat JSON output linter : Ok 44 98: perf stat JSON output linter : Ok 45 98: perf stat JSON output linter : Ok 46 98: perf stat JSON output linter : FAILED! 47 98: perf stat JSON output linter : Ok 48 98: perf stat JSON output linter : FAILED! 49 98: perf stat JSON output linter : FAILED! 50 98: perf stat JSON output linter : FAILED! 51 98: perf stat JSON output linter : FAILED! 52 98: perf stat JSON output linter : Ok 53 98: perf stat JSON output linter : FAILED! 54 98: perf stat JSON output linter : Ok 55 98: perf stat JSON output linter : Ok 56 98: perf stat JSON output linter : FAILED! 57 98: perf stat JSON output linter : Ok 58 98: perf stat JSON output linter : Ok 59 98: perf stat JSON output linter : FAILED! 60 98: perf stat JSON output linter : Ok 61 98: perf stat JSON output linter : FAILED! 62 98: perf stat JSON output linter : Ok 63 98: perf stat JSON output linter : Ok 64 98: perf stat JSON output linter : Ok 65 98: perf stat JSON output linter : Ok 66 98: perf stat JSON output linter : Ok 67 98: perf stat JSON output linter : Ok 68 98: perf stat JSON output linter : Ok 69 98: perf stat JSON output linter : Ok 70 98: perf stat JSON output linter : Ok 71 98: perf stat JSON output linter : FAILED! 72 98: perf stat JSON output linter : FAILED! 73 98: perf stat JSON output linter : Ok 74 98: perf stat JSON output linter : FAILED! 75 98: perf stat JSON output linter : Ok 76 98: perf stat JSON output linter : FAILED! 77 98: perf stat JSON output linter : Ok 78 98: perf stat JSON output linter : FAILED! 79 98: perf stat JSON output linter : FAILED! 80 98: perf stat JSON output linter : FAILED! 81 98: perf stat JSON output linter : Ok 82 98: perf stat JSON output linter : FAILED! 83 98: perf stat JSON output linter : FAILED! 84 98: perf stat JSON output linter : Ok 85 98: perf stat JSON output linter : Ok 86 98: perf stat JSON output linter : Ok 87 98: perf stat JSON output linter : FAILED! 88 98: perf stat JSON output linter : FAILED! 89 98: perf stat JSON output linter : Ok 90 98: perf stat JSON output linter : FAILED! 91 98: perf stat JSON output linter : FAILED! 92 98: perf stat JSON output linter : Ok 93 98: perf stat JSON output linter : FAILED! 94 98: perf stat JSON output linter : FAILED! 95 98: perf stat JSON output linter : FAILED! 96 98: perf stat JSON output linter : FAILED! 97 98: perf stat JSON output linter : FAILED! 98 98: perf stat JSON output linter : Ok 99 98: perf stat JSON output linter : Ok 100 98: perf stat JSON output linter : FAILED! [root@quaco ~]# > Fixes: 0c343af2a2f8 ("perf test: JSON format checking") > > Signed-off-by: Michael Petlan <mpetlan@redhat.com> > --- > .../tests/shell/lib/perf_json_output_lint.py | 16 ++++++++-------- > 1 file changed, 8 insertions(+), 8 deletions(-) > > diff --git a/tools/perf/tests/shell/lib/perf_json_output_lint.py b/tools/perf/tests/shell/lib/perf_json_output_lint.py > index d90f8d102eb9..4f1bbb3f07ec 100644 > --- a/tools/perf/tests/shell/lib/perf_json_output_lint.py > +++ b/tools/perf/tests/shell/lib/perf_json_output_lint.py > @@ -40,17 +40,17 @@ def is_counter_value(num): > return isfloat(num) or num == '<not counted>' or num == '<not supported>' > > def check_json_output(expected_items): > - if expected_items != -1: > + if expected_items: > for line in Lines: > if 'failed' not in line: > count = 0 > - count = line.count(',') > - if count != expected_items and count >= 1 and count <= 3 and 'metric-value' in line: > + count = line.count(' : ') > + if count not in expected_items and count >= 2 and count <= 4 and 'metric-value' in line: > # Events that generate >1 metric may have isolated metric > # values and possibly other prefixes like interval, core and > # aggregate-number. > continue > - if count != expected_items: > + if count not in expected_items: > raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' > f' in \'{line}\'') > checks = { > @@ -82,14 +82,14 @@ def check_json_output(expected_items): > > try: > if args.no_args or args.system_wide or args.event: > - expected_items = 6 > + expected_items = [7, 9] > elif args.interval or args.per_thread or args.system_wide_no_aggr: > - expected_items = 7 > + expected_items = [8, 10] > elif args.per_core or args.per_socket or args.per_node or args.per_die: > - expected_items = 8 > + expected_items = [9, 11] > else: > # If no option is specified, don't check the number of items. > - expected_items = -1 > + expected_items = [] > check_json_output(expected_items) > except: > print('Test failed for input:\n' + '\n'.join(Lines)) > -- > 2.18.4 > -- - Arnaldo ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-27 12:26 ` Arnaldo Carvalho de Melo @ 2023-01-27 12:30 ` Arnaldo Carvalho de Melo 2023-01-31 17:14 ` Michael Petlan 0 siblings, 1 reply; 18+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-01-27 12:30 UTC (permalink / raw) To: Michael Petlan Cc: linux-perf-users, acme, qzhao, cjense, Ian Rogers, Linux Kernel Mailing List, Namhyung Kim, Jiri Olsa, Adrian Hunter Em Fri, Jan 27, 2023 at 09:26:03AM -0300, Arnaldo Carvalho de Melo escreveu: > Em Fri, Jan 20, 2023 at 02:40:39PM +0100, Michael Petlan escreveu: > > The test fails on CPUs with topdown metrics, where it is common to print > > two metrics per line. Since these are included in default event set for > > `perf stat -- something`, it causes the "no args" subtest to fail due to > > unexpected member count. We need to accept 7 or 9 members in that case. > > > > Coming to that, counting commas in the JSON line and consider it a number > > of elements is incorrect and misleading. There should be +1 element than > > the count of commas, while also, commas can potentially appear in the > > event names. Count " : " substrings rather, since these better fit to > > what should be actually counted. > > Before I apply this first patch I can run, as root, the 'perf test' JSON > lint 100 times without problems: > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > 1 98: perf stat JSON output linter : Ok > 2 98: perf stat JSON output linter : Ok > 3 98: perf stat JSON output linter : Ok > 4 98: perf stat JSON output linter : Ok > <SNIP> > 96 98: perf stat JSON output linter : Ok > 97 98: perf stat JSON output linter : Ok > 98 98: perf stat JSON output linter : Ok > 99 98: perf stat JSON output linter : Ok > 100 98: perf stat JSON output linter : Ok > [root@quaco ~]# > > After applying it it fails seemingly randomly, I'll remove both patches > from my tmp.perf/core branch and investigate. > > [acme@quaco perf]$ git log --oneline -1 > fdafd42aac3629db (HEAD) perf stat: Fix JSON metric printout for multiple metrics per line > [acme@quaco perf]$ perf -v > perf version 6.2.rc5.gfdafd42aac36 > [acme@quaco perf]$ > [root@quaco ~]# perf -v > perf version 6.2.rc5.gfdafd42aac36 > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > [root@quaco ~]# perf -v > perf version 6.2.rc5.gfdafd42aac36 > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > 1 98: perf stat JSON output linter : Ok > 2 98: perf stat JSON output linter : Ok > 3 98: perf stat JSON output linter : FAILED! > 4 98: perf stat JSON output linter : Ok BTW, after applying the second patch, the one for 'perf test', the problem persists: [acme@quaco perf]$ git log --oneline -1 320cd37176508ec2 (HEAD, acme/tmp.perf/core, acme.korg/tmp.perf/core) perf test: Fix JSON format linter test checks [acme@quaco perf]$ perf -v perf version 6.2.rc5.g320cd3717650 [acme@quaco perf]$ [root@quaco ~]# perf -v perf version 6.2.rc5.g320cd3717650 [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done 1 98: perf stat JSON output linter : Ok 2 98: perf stat JSON output linter : FAILED! 3 98: perf stat JSON output linter : Ok 4 98: perf stat JSON output linter : Ok 5 98: perf stat JSON output linter : FAILED! 6 98: perf stat JSON output linter : Ok 7 98: perf stat JSON output linter : FAILED! 8 98: perf stat JSON output linter : Ok 9 98: perf stat JSON output linter : Ok 10 98: perf stat JSON output linter : FAILED! 11 98: perf stat JSON output linter : FAILED! 12 98: perf stat JSON output linter : FAILED! 13 98: perf stat JSON output linter : Ok 14 98: perf stat JSON output linter : Ok 15 98: perf stat JSON output linter : FAILED! 16 98: perf stat JSON output linter : FAILED! 17 98: perf stat JSON output linter : FAILED! 18 98: perf stat JSON output linter :^C [root@quaco ~]# When it works: [root@quaco ~]# perf test -v 98 98: perf stat JSON output linter : --- start --- test child forked, pid 62202 Checking json output: no args [Success] Checking json output: system wide [Success] Checking json output: interval [Success] Checking json output: event [Success] Checking json output: per thread [Success] Checking json output: per node [Success] Checking json output: system wide Checking json output: system wide no aggregation [Success] Checking json output: per core [Success] Checking json output: per die [Success] Checking json output: per socket [Success] test child finished with 0 ---- end ---- perf stat JSON output linter: Ok [root@quaco ~]# When it fails: [root@quaco ~]# perf test -v 98 98: perf stat JSON output linter : --- start --- test child forked, pid 62270 Checking json output: no args [Success] Checking json output: system wide [Success] Checking json output: interval [Success] Checking json output: event [Success] Checking json output: per thread Test failed for input: {"thread" : "rcu_preempt-16", "counter-value" : "0.018340", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 19071, "pcnt-running" : 100.00, "metric-value" : 0.001758, "metric-unit" : "CPUs utilized"} {"thread" : "gnome-terminal--2977", "counter-value" : "0.061868", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 0.005930, "metric-unit" : "CPUs utilized"} {"thread" : "perf-62294", "counter-value" : "9.398635", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 9398904, "pcnt-running" : 100.00, "metric-value" : 0.900916, "metric-unit" : "CPUs utilized"} {"thread" : "rcu_preempt-16", "counter-value" : "4.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 15203, "pcnt-running" : 100.00, "metric-value" : 218.102508, "metric-unit" : "K/sec"} {"thread" : "gnome-terminal--2977", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 16.163445, "metric-unit" : "K/sec"} {"thread" : "perf-62294", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 9388658, "pcnt-running" : 100.00, "metric-value" : 106.398429, "metric-unit" : "/sec"} {"thread" : "rcu_preempt-16", "counter-value" : "1.000000", "unit" : "", "event" : "cpu-migrations", "event-runtime" : 12511, "pcnt-running" : 100.00, "metric-value" : 54.525627, "metric-unit" : "K/sec"} {"thread" : "perf-62294", "counter-value" : "2.000000", "unit" : "", "event" : "page-faults", "event-runtime" : 9427495, "pcnt-running" : 100.00, "metric-value" : 212.796858, "metric-unit" : "/sec"} {"thread" : "rcu_preempt-16", "counter-value" : "41498.000000", "unit" : "", "event" : "cycles", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 2.262704, "metric-unit" : "GHz"} {"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} {"thread" : "perf-62294", "counter-value" : "36686750.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9439269, "pcnt-running" : 100.00, "metric-value" : 3.903413, "metric-unit" : "GHz"} {"thread" : "rcu_preempt-16", "counter-value" : "25086.000000", "unit" : "", "event" : "instructions", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 0.604511, "metric-unit" : "insn per cycle"} {"thread" : "ksoftirqd/1-22", "counter-value" : "13360.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.559394, "metric-unit" : "insn per cycle"} {"thread" : "perf-62294", "counter-value" : "7905940.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9438686, "pcnt-running" : 100.00, "metric-value" : 0.215499, "metric-unit" : "insn per cycle"} {"thread" : "rcu_preempt-16", "counter-value" : "3951.000000", "unit" : "", "event" : "branches", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 215.430752, "metric-unit" : "M/sec"} {"thread" : "ksoftirqd/1-22", "counter-value" : "2822.000000", "unit" : "", "event" : "branches", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "/sec"} {"thread" : "perf-62294", "counter-value" : "1691804.000000", "unit" : "", "event" : "branches", "event-runtime" : 9474118, "pcnt-running" : 100.00, "metric-value" : 180.005288, "metric-unit" : "M/sec"} {"thread" : "rcu_preempt-16", "counter-value" : "279.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 7.061503, "metric-unit" : "of all branches"} {"thread" : "ksoftirqd/1-22", "counter-value" : "153.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 5.421687, "metric-unit" : "of all branches"} {"thread" : "kworker/1:2-events-752", "counter-value" : "121.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9850, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "of all branches"} {"thread" : "perf-62294", "counter-value" : "52693.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9451948, "pcnt-running" : 100.00, "metric-value" : 3.114604, "metric-unit" : "of all branches"} Traceback (most recent call last): File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 93, in <module> check_json_output(expected_items) File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 54, in check_json_output raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' RuntimeError: wrong number of fields. counted 6 expected [8, 10] in '{"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} ' test child finished with -1 ---- end ---- perf stat JSON output linter: FAILED! [root@quaco ~]# ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-27 12:30 ` Arnaldo Carvalho de Melo @ 2023-01-31 17:14 ` Michael Petlan 2023-02-02 1:18 ` Arnaldo Carvalho de Melo 0 siblings, 1 reply; 18+ messages in thread From: Michael Petlan @ 2023-01-31 17:14 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: linux-perf-users, acme, qzhao, cjense, Ian Rogers, Linux Kernel Mailing List, Namhyung Kim, Jiri Olsa, Adrian Hunter On Fri, 27 Jan 2023, Arnaldo Carvalho de Melo wrote: > Em Fri, Jan 27, 2023 at 09:26:03AM -0300, Arnaldo Carvalho de Melo escreveu: [...] > > Before I apply this first patch I can run, as root, the 'perf test' JSON > > lint 100 times without problems: > > > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > 1 98: perf stat JSON output linter : Ok > > 2 98: perf stat JSON output linter : Ok > > 3 98: perf stat JSON output linter : Ok > > 4 98: perf stat JSON output linter : Ok > > <SNIP> > > 96 98: perf stat JSON output linter : Ok > > 97 98: perf stat JSON output linter : Ok > > 98 98: perf stat JSON output linter : Ok > > 99 98: perf stat JSON output linter : Ok > > 100 98: perf stat JSON output linter : Ok > > [root@quaco ~]# > > > > After applying it it fails seemingly randomly, I'll remove both patches > > from my tmp.perf/core branch and investigate. Hello Arnaldo. Have you found anything? Which patch of the two causes the failures? The one that changes the JSON printing or the second that changes the test? I hope that the JSON printing is now correct, it seems to be, at least on my machine + the SPR box I was debugging this on. > > > > [acme@quaco perf]$ git log --oneline -1 > > fdafd42aac3629db (HEAD) perf stat: Fix JSON metric printout for multiple metrics per line > > [acme@quaco perf]$ perf -v > > perf version 6.2.rc5.gfdafd42aac36 > > [acme@quaco perf]$ > > [root@quaco ~]# perf -v > > perf version 6.2.rc5.gfdafd42aac36 > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > [root@quaco ~]# perf -v > > perf version 6.2.rc5.gfdafd42aac36 > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > 1 98: perf stat JSON output linter : Ok > > 2 98: perf stat JSON output linter : Ok > > 3 98: perf stat JSON output linter : FAILED! > > 4 98: perf stat JSON output linter : Ok > > BTW, after applying the second patch, the one for 'perf test', the > problem persists: > > [acme@quaco perf]$ git log --oneline -1 > 320cd37176508ec2 (HEAD, acme/tmp.perf/core, acme.korg/tmp.perf/core) perf test: Fix JSON format linter test checks > [acme@quaco perf]$ perf -v > perf version 6.2.rc5.g320cd3717650 > [acme@quaco perf]$ > [root@quaco ~]# perf -v > perf version 6.2.rc5.g320cd3717650 > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > 1 98: perf stat JSON output linter : Ok > 2 98: perf stat JSON output linter : FAILED! > 3 98: perf stat JSON output linter : Ok > 4 98: perf stat JSON output linter : Ok > 5 98: perf stat JSON output linter : FAILED! > 6 98: perf stat JSON output linter : Ok > 7 98: perf stat JSON output linter : FAILED! > 8 98: perf stat JSON output linter : Ok > 9 98: perf stat JSON output linter : Ok > 10 98: perf stat JSON output linter : FAILED! > 11 98: perf stat JSON output linter : FAILED! > 12 98: perf stat JSON output linter : FAILED! > 13 98: perf stat JSON output linter : Ok > 14 98: perf stat JSON output linter : Ok > 15 98: perf stat JSON output linter : FAILED! > 16 98: perf stat JSON output linter : FAILED! > 17 98: perf stat JSON output linter : FAILED! > 18 98: perf stat JSON output linter :^C > [root@quaco ~]# > > When it works: > > [root@quaco ~]# perf test -v 98 > 98: perf stat JSON output linter : > --- start --- > test child forked, pid 62202 > Checking json output: no args [Success] > Checking json output: system wide [Success] > Checking json output: interval [Success] > Checking json output: event [Success] > Checking json output: per thread [Success] > Checking json output: per node [Success] > Checking json output: system wide Checking json output: system wide no aggregation [Success] > Checking json output: per core [Success] > Checking json output: per die [Success] > Checking json output: per socket [Success] > test child finished with 0 > ---- end ---- > perf stat JSON output linter: Ok > [root@quaco ~]# > > When it fails: > > [root@quaco ~]# perf test -v 98 > 98: perf stat JSON output linter : > --- start --- > test child forked, pid 62270 > Checking json output: no args [Success] > Checking json output: system wide [Success] > Checking json output: interval [Success] > Checking json output: event [Success] > Checking json output: per thread Test failed for input: > {"thread" : "rcu_preempt-16", "counter-value" : "0.018340", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 19071, "pcnt-running" : 100.00, "metric-value" : 0.001758, "metric-unit" : "CPUs utilized"} > > {"thread" : "gnome-terminal--2977", "counter-value" : "0.061868", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 0.005930, "metric-unit" : "CPUs utilized"} > > {"thread" : "perf-62294", "counter-value" : "9.398635", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 9398904, "pcnt-running" : 100.00, "metric-value" : 0.900916, "metric-unit" : "CPUs utilized"} > > {"thread" : "rcu_preempt-16", "counter-value" : "4.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 15203, "pcnt-running" : 100.00, "metric-value" : 218.102508, "metric-unit" : "K/sec"} > > {"thread" : "gnome-terminal--2977", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 16.163445, "metric-unit" : "K/sec"} > > {"thread" : "perf-62294", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 9388658, "pcnt-running" : 100.00, "metric-value" : 106.398429, "metric-unit" : "/sec"} > > {"thread" : "rcu_preempt-16", "counter-value" : "1.000000", "unit" : "", "event" : "cpu-migrations", "event-runtime" : 12511, "pcnt-running" : 100.00, "metric-value" : 54.525627, "metric-unit" : "K/sec"} > > {"thread" : "perf-62294", "counter-value" : "2.000000", "unit" : "", "event" : "page-faults", "event-runtime" : 9427495, "pcnt-running" : 100.00, "metric-value" : 212.796858, "metric-unit" : "/sec"} > > {"thread" : "rcu_preempt-16", "counter-value" : "41498.000000", "unit" : "", "event" : "cycles", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 2.262704, "metric-unit" : "GHz"} > > {"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} > > {"thread" : "perf-62294", "counter-value" : "36686750.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9439269, "pcnt-running" : 100.00, "metric-value" : 3.903413, "metric-unit" : "GHz"} > > {"thread" : "rcu_preempt-16", "counter-value" : "25086.000000", "unit" : "", "event" : "instructions", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 0.604511, "metric-unit" : "insn per cycle"} > > {"thread" : "ksoftirqd/1-22", "counter-value" : "13360.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.559394, "metric-unit" : "insn per cycle"} > > {"thread" : "perf-62294", "counter-value" : "7905940.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9438686, "pcnt-running" : 100.00, "metric-value" : 0.215499, "metric-unit" : "insn per cycle"} > > {"thread" : "rcu_preempt-16", "counter-value" : "3951.000000", "unit" : "", "event" : "branches", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 215.430752, "metric-unit" : "M/sec"} > > {"thread" : "ksoftirqd/1-22", "counter-value" : "2822.000000", "unit" : "", "event" : "branches", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "/sec"} > > {"thread" : "perf-62294", "counter-value" : "1691804.000000", "unit" : "", "event" : "branches", "event-runtime" : 9474118, "pcnt-running" : 100.00, "metric-value" : 180.005288, "metric-unit" : "M/sec"} > > {"thread" : "rcu_preempt-16", "counter-value" : "279.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 7.061503, "metric-unit" : "of all branches"} > > {"thread" : "ksoftirqd/1-22", "counter-value" : "153.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 5.421687, "metric-unit" : "of all branches"} > > {"thread" : "kworker/1:2-events-752", "counter-value" : "121.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9850, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "of all branches"} > > {"thread" : "perf-62294", "counter-value" : "52693.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9451948, "pcnt-running" : 100.00, "metric-value" : 3.114604, "metric-unit" : "of all branches"} > > Traceback (most recent call last): > File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 93, in <module> > check_json_output(expected_items) > File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 54, in check_json_output > raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' > RuntimeError: wrong number of fields. counted 6 expected [8, 10] in '{"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} Here it seems that the test finds unexpected number of entities in the line. It can be, 6 is not in [8, 10]. However, since the line looks OK, we should expand the set of accepted results to [6, 8, 10] then. If this fails even without the test patch, so only with my JSON printing patch, AND it does NOT fail without it, it seems very weird. The patch fixes the JSON format breakage that happens when two metrics are per line. The JSON output above looks sane, especially looking at the line that failed: {"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} It rather seems that depending on the values counted, something gets computed or not, and that changes the output, so sometimes a line with unexpected count of elements appears there. Couldn't anything else cause the change of the output? Michael > ' > test child finished with -1 > ---- end ---- > perf stat JSON output linter: FAILED! > [root@quaco ~]# > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 2/2] perf test: Fix JSON format linter test checks 2023-01-31 17:14 ` Michael Petlan @ 2023-02-02 1:18 ` Arnaldo Carvalho de Melo 0 siblings, 0 replies; 18+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-02-02 1:18 UTC (permalink / raw) To: Michael Petlan Cc: linux-perf-users, acme, qzhao, cjense, Ian Rogers, Linux Kernel Mailing List, Namhyung Kim, Jiri Olsa, Adrian Hunter Em Tue, Jan 31, 2023 at 06:14:17PM +0100, Michael Petlan escreveu: > On Fri, 27 Jan 2023, Arnaldo Carvalho de Melo wrote: > > Em Fri, Jan 27, 2023 at 09:26:03AM -0300, Arnaldo Carvalho de Melo escreveu: > [...] > > > > Before I apply this first patch I can run, as root, the 'perf test' JSON > > > lint 100 times without problems: > > > > > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > > 1 98: perf stat JSON output linter : Ok > > > 2 98: perf stat JSON output linter : Ok > > > 3 98: perf stat JSON output linter : Ok > > > 4 98: perf stat JSON output linter : Ok > > > <SNIP> > > > 96 98: perf stat JSON output linter : Ok > > > 97 98: perf stat JSON output linter : Ok > > > 98 98: perf stat JSON output linter : Ok > > > 99 98: perf stat JSON output linter : Ok > > > 100 98: perf stat JSON output linter : Ok > > > [root@quaco ~]# > > > > > > After applying it it fails seemingly randomly, I'll remove both patches > > > from my tmp.perf/core branch and investigate. > > Hello Arnaldo. Have you found anything? > > Which patch of the two causes the failures? The one that changes the JSON Its described below, the first patch introduces the problem. IT may well be due to the Intel model of my test machine, from what I could read on the other threads about the "all metrics test", but I haven't had time to fully investigate. [acme@quaco pahole]$ grep -m1 ^model\ name /proc/cpuinfo model name : Intel(R) Core(TM) i7-8650U CPU @ 1.90GHz [acme@quaco pahole]$ - Arnaldo > printing or the second that changes the test? > > I hope that the JSON printing is now correct, it seems to be, at least on my > machine + the SPR box I was debugging this on. > > > > > > > > [acme@quaco perf]$ git log --oneline -1 > > > fdafd42aac3629db (HEAD) perf stat: Fix JSON metric printout for multiple metrics per line > > > [acme@quaco perf]$ perf -v > > > perf version 6.2.rc5.gfdafd42aac36 > > > [acme@quaco perf]$ > > > [root@quaco ~]# perf -v > > > perf version 6.2.rc5.gfdafd42aac36 > > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > > [root@quaco ~]# perf -v > > > perf version 6.2.rc5.gfdafd42aac36 > > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > > 1 98: perf stat JSON output linter : Ok > > > 2 98: perf stat JSON output linter : Ok > > > 3 98: perf stat JSON output linter : FAILED! > > > 4 98: perf stat JSON output linter : Ok > > > > BTW, after applying the second patch, the one for 'perf test', the > > problem persists: > > > > [acme@quaco perf]$ git log --oneline -1 > > 320cd37176508ec2 (HEAD, acme/tmp.perf/core, acme.korg/tmp.perf/core) perf test: Fix JSON format linter test checks > > [acme@quaco perf]$ perf -v > > perf version 6.2.rc5.g320cd3717650 > > [acme@quaco perf]$ > > [root@quaco ~]# perf -v > > perf version 6.2.rc5.g320cd3717650 > > [root@quaco ~]# for a in $(seq 100) ; do echo -n $a ; perf test 98 ; done > > 1 98: perf stat JSON output linter : Ok > > 2 98: perf stat JSON output linter : FAILED! > > 3 98: perf stat JSON output linter : Ok > > 4 98: perf stat JSON output linter : Ok > > 5 98: perf stat JSON output linter : FAILED! > > 6 98: perf stat JSON output linter : Ok > > 7 98: perf stat JSON output linter : FAILED! > > 8 98: perf stat JSON output linter : Ok > > 9 98: perf stat JSON output linter : Ok > > 10 98: perf stat JSON output linter : FAILED! > > 11 98: perf stat JSON output linter : FAILED! > > 12 98: perf stat JSON output linter : FAILED! > > 13 98: perf stat JSON output linter : Ok > > 14 98: perf stat JSON output linter : Ok > > 15 98: perf stat JSON output linter : FAILED! > > 16 98: perf stat JSON output linter : FAILED! > > 17 98: perf stat JSON output linter : FAILED! > > 18 98: perf stat JSON output linter :^C > > [root@quaco ~]# > > > > When it works: > > > > [root@quaco ~]# perf test -v 98 > > 98: perf stat JSON output linter : > > --- start --- > > test child forked, pid 62202 > > Checking json output: no args [Success] > > Checking json output: system wide [Success] > > Checking json output: interval [Success] > > Checking json output: event [Success] > > Checking json output: per thread [Success] > > Checking json output: per node [Success] > > Checking json output: system wide Checking json output: system wide no aggregation [Success] > > Checking json output: per core [Success] > > Checking json output: per die [Success] > > Checking json output: per socket [Success] > > test child finished with 0 > > ---- end ---- > > perf stat JSON output linter: Ok > > [root@quaco ~]# > > > > When it fails: > > > > [root@quaco ~]# perf test -v 98 > > 98: perf stat JSON output linter : > > --- start --- > > test child forked, pid 62270 > > Checking json output: no args [Success] > > Checking json output: system wide [Success] > > Checking json output: interval [Success] > > Checking json output: event [Success] > > Checking json output: per thread Test failed for input: > > {"thread" : "rcu_preempt-16", "counter-value" : "0.018340", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 19071, "pcnt-running" : 100.00, "metric-value" : 0.001758, "metric-unit" : "CPUs utilized"} > > > > {"thread" : "gnome-terminal--2977", "counter-value" : "0.061868", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 0.005930, "metric-unit" : "CPUs utilized"} > > > > {"thread" : "perf-62294", "counter-value" : "9.398635", "unit" : "msec", "event" : "cpu-clock", "event-runtime" : 9398904, "pcnt-running" : 100.00, "metric-value" : 0.900916, "metric-unit" : "CPUs utilized"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "4.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 15203, "pcnt-running" : 100.00, "metric-value" : 218.102508, "metric-unit" : "K/sec"} > > > > {"thread" : "gnome-terminal--2977", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 62075, "pcnt-running" : 100.00, "metric-value" : 16.163445, "metric-unit" : "K/sec"} > > > > {"thread" : "perf-62294", "counter-value" : "1.000000", "unit" : "", "event" : "context-switches", "event-runtime" : 9388658, "pcnt-running" : 100.00, "metric-value" : 106.398429, "metric-unit" : "/sec"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "1.000000", "unit" : "", "event" : "cpu-migrations", "event-runtime" : 12511, "pcnt-running" : 100.00, "metric-value" : 54.525627, "metric-unit" : "K/sec"} > > > > {"thread" : "perf-62294", "counter-value" : "2.000000", "unit" : "", "event" : "page-faults", "event-runtime" : 9427495, "pcnt-running" : 100.00, "metric-value" : 212.796858, "metric-unit" : "/sec"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "41498.000000", "unit" : "", "event" : "cycles", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 2.262704, "metric-unit" : "GHz"} > > > > {"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} > > > > {"thread" : "perf-62294", "counter-value" : "36686750.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9439269, "pcnt-running" : 100.00, "metric-value" : 3.903413, "metric-unit" : "GHz"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "25086.000000", "unit" : "", "event" : "instructions", "event-runtime" : 20944, "pcnt-running" : 100.00, "metric-value" : 0.604511, "metric-unit" : "insn per cycle"} > > > > {"thread" : "ksoftirqd/1-22", "counter-value" : "13360.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.559394, "metric-unit" : "insn per cycle"} > > > > {"thread" : "perf-62294", "counter-value" : "7905940.000000", "unit" : "", "event" : "instructions", "event-runtime" : 9438686, "pcnt-running" : 100.00, "metric-value" : 0.215499, "metric-unit" : "insn per cycle"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "3951.000000", "unit" : "", "event" : "branches", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 215.430752, "metric-unit" : "M/sec"} > > > > {"thread" : "ksoftirqd/1-22", "counter-value" : "2822.000000", "unit" : "", "event" : "branches", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "/sec"} > > > > {"thread" : "perf-62294", "counter-value" : "1691804.000000", "unit" : "", "event" : "branches", "event-runtime" : 9474118, "pcnt-running" : 100.00, "metric-value" : 180.005288, "metric-unit" : "M/sec"} > > > > {"thread" : "rcu_preempt-16", "counter-value" : "279.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 16533, "pcnt-running" : 100.00, "metric-value" : 7.061503, "metric-unit" : "of all branches"} > > > > {"thread" : "ksoftirqd/1-22", "counter-value" : "153.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9949, "pcnt-running" : 100.00, "metric-value" : 5.421687, "metric-unit" : "of all branches"} > > > > {"thread" : "kworker/1:2-events-752", "counter-value" : "121.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9850, "pcnt-running" : 100.00, "metric-value" : 0.000000, "metric-unit" : "of all branches"} > > > > {"thread" : "perf-62294", "counter-value" : "52693.000000", "unit" : "", "event" : "branch-misses", "event-runtime" : 9451948, "pcnt-running" : 100.00, "metric-value" : 3.114604, "metric-unit" : "of all branches"} > > > > Traceback (most recent call last): > > File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 93, in <module> > > check_json_output(expected_items) > > File "/home/acme/libexec/perf-core/tests/shell/lib/perf_json_output_lint.py", line 54, in check_json_output > > raise RuntimeError(f'wrong number of fields. counted {count} expected {expected_items}' > > RuntimeError: wrong number of fields. counted 6 expected [8, 10] in '{"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} > > Here it seems that the test finds unexpected number of entities in the > line. It can be, 6 is not in [8, 10]. However, since the line looks OK, > we should expand the set of accepted results to [6, 8, 10] then. > > If this fails even without the test patch, so only with my JSON printing > patch, AND it does NOT fail without it, it seems very weird. The patch > fixes the JSON format breakage that happens when two metrics are per line. > > The JSON output above looks sane, especially looking at the line that > failed: > > {"thread" : "ksoftirqd/1-22", "counter-value" : "23883.000000", "unit" : "", "event" : "cycles", "event-runtime" : 9949, "pcnt-running" : 100.00} > > It rather seems that depending on the values counted, something gets > computed or not, and that changes the output, so sometimes a line with > unexpected count of elements appears there. Couldn't anything else > cause the change of the output? > > Michael > > ' > > test child finished with -1 > > ---- end ---- > > perf stat JSON output linter: FAILED! > > [root@quaco ~]# > > > > > -- - Arnaldo ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 0/2] perf test: Fix JSON linter 2023-01-20 13:40 [PATCH 0/2] perf test: Fix JSON linter Michael Petlan 2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan 2023-01-20 13:40 ` [PATCH 2/2] perf test: Fix JSON format linter test checks Michael Petlan @ 2023-01-20 17:37 ` Ian Rogers 2023-01-23 6:48 ` Namhyung Kim ` (2 more replies) 2 siblings, 3 replies; 18+ messages in thread From: Ian Rogers @ 2023-01-20 17:37 UTC (permalink / raw) To: Michael Petlan, Namhyung Kim; +Cc: linux-perf-users, acme, acme, qzhao, cjense On Fri, Jan 20, 2023 at 5:41 AM Michael Petlan <mpetlan@redhat.com> wrote: > > Hello all. > > We have observed issues with the 'perf stat JSON output linter' testcase > on systems that allow topdown metrics. > > ========================= > > 1) The topdown metrics handling hardcodes printing more than one metric > per line (refer to util/stat-shadow.c): > > if (retiring > 0.7 && heavy_ops > 0.1) > color = PERF_COLOR_GREEN; > print_metric(config, ctxp, color, "%8.1f%%", "Heavy Operations", > heavy_ops * 100.); > if (retiring > 0.7 && light_ops > 0.6) > color = PERF_COLOR_GREEN; > else > color = NULL; > print_metric(config, ctxp, color, "%8.1f%%", "Light Operations", > light_ops * 100.); > > Thus, the test cannot rely on the fact that there will be only one > metric per line. Right, these implicit metrics are also an issue with --metric-only. It isn't clear from the command line flags when implicit and listed metrics should be generated. The topdown events (Icelake+) made the implicit metric problem worse, and they likely didn't exist or weren't tested at the time of the json output. > 2) Since the JSON printing engine thinks that one and only one metric > is printed, it always closes the line by adding '}'. This is not true, > so I have fixed the comma printing and adjusted the engine to be > capable of printing 1-N metrics and then close the line. So the current printing code is messy. For example, there is a newline callback function, but that has little meaning for json where everything is on a newline. For CSV mode, adding a summary used to cause a column to suddenly appear on the left for the row containing the summary. I believe the right thing to do is a refactor and recently I did a similar refactor for 'perf list': https://lore.kernel.org/lkml/20221114210723.2749751-11-irogers@google.com/ So it is strange that metrics are "shadows" of events, but whatever the point is to think about the printing API. In the change linked above you can see that everytime something is printed the print handling code is given all the information and the print handling code has state. Based on the state and callback's information, the print handling code can do nothing, properly format for CSV, json, etc. This gets completely away from the kind of madness of branches and whac-a-mole the code currently has. I'm happy to look at doing the refactor to be similar to 'perf list'/builtin-list.c. Namhyung I thought might have gotten to it with his recent work on improving aggregation. If I hear silence then I'll assume that is a request I do it :-) Pragmatically in the short term we could land your changes, but I worry they are more of the whac-a-mole and something somewhere else will break. Which is why we have a test, and so I'm not overly worried. I can download and test too. Anyway, sorry for the issue and let me know what you think. Thanks, Ian > ========================= > > On machines that don't support topdown, the problem can be shown by > doubling the following line in util/stat-shadow.c, so that the simple > 'insn per cycle' metric is printed twice: > > print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio); > > The worst problem is that the JSON line is broken, such as: > > ... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit" > : "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ... > here ^^^^^ > > ========================= > > The first patch solves the JSON output correctness, the second tries > to adjust the testcase to some extent, so that it should work on the > topdown-capable machines. > > However, it's highly possible that the testcase will have to be fixed > or maybe rewritten in future. First, it has quite naive evaluation of > what's expected/correct/etc. Second, it does no JSON format validation > at all. As a linter it should do so though. > > *** > > For further discussion: What about removing the check for number of > expected elements in the line and just check for the keywords, such > as "metric-value", "counter-value", "event", etc. and for some values > that should be numeric. And, do proper JSON format sanity check? > > > Thank you for inputs! > > Michael > > > > > Michael Petlan (2): > perf stat: Fix JSON metric printout for multiple metrics per line > perf test: Fix JSON format linter test checks > > .../tests/shell/lib/perf_json_output_lint.py | 16 +++++------ > tools/perf/util/stat-display.c | 28 +++++++++++-------- > 2 files changed, 24 insertions(+), 20 deletions(-) > > -- > 2.18.4 > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 0/2] perf test: Fix JSON linter 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers @ 2023-01-23 6:48 ` Namhyung Kim 2023-01-23 13:38 ` Arnaldo Carvalho de Melo 2023-01-24 17:39 ` Michael Petlan 2 siblings, 0 replies; 18+ messages in thread From: Namhyung Kim @ 2023-01-23 6:48 UTC (permalink / raw) To: Ian Rogers; +Cc: Michael Petlan, linux-perf-users, acme, acme, qzhao, cjense On Fri, Jan 20, 2023 at 9:37 AM Ian Rogers <irogers@google.com> wrote: > > On Fri, Jan 20, 2023 at 5:41 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > Hello all. > > > > We have observed issues with the 'perf stat JSON output linter' testcase > > on systems that allow topdown metrics. > > > > ========================= > > > > 1) The topdown metrics handling hardcodes printing more than one metric > > per line (refer to util/stat-shadow.c): > > > > if (retiring > 0.7 && heavy_ops > 0.1) > > color = PERF_COLOR_GREEN; > > print_metric(config, ctxp, color, "%8.1f%%", "Heavy Operations", > > heavy_ops * 100.); > > if (retiring > 0.7 && light_ops > 0.6) > > color = PERF_COLOR_GREEN; > > else > > color = NULL; > > print_metric(config, ctxp, color, "%8.1f%%", "Light Operations", > > light_ops * 100.); > > > > Thus, the test cannot rely on the fact that there will be only one > > metric per line. > > Right, these implicit metrics are also an issue with --metric-only. It > isn't clear from the command line flags when implicit and listed > metrics should be generated. The topdown events (Icelake+) made the > implicit metric problem worse, and they likely didn't exist or weren't > tested at the time of the json output. > > > 2) Since the JSON printing engine thinks that one and only one metric > > is printed, it always closes the line by adding '}'. This is not true, > > so I have fixed the comma printing and adjusted the engine to be > > capable of printing 1-N metrics and then close the line. > > So the current printing code is messy. For example, there is a newline > callback function, but that has little meaning for json where > everything is on a newline. For CSV mode, adding a summary used to > cause a column to suddenly appear on the left for the row containing > the summary. I believe the right thing to do is a refactor and > recently I did a similar refactor for 'perf list': > https://lore.kernel.org/lkml/20221114210723.2749751-11-irogers@google.com/ > So it is strange that metrics are "shadows" of events, but whatever > the point is to think about the printing API. In the change linked > above you can see that everytime something is printed the print > handling code is given all the information and the print handling code > has state. Based on the state and callback's information, the print > handling code can do nothing, properly format for CSV, json, etc. This > gets completely away from the kind of madness of branches and > whac-a-mole the code currently has. Maybe we could reuse the tools/bpf/bpftool/json_writer.[ch]. It'd be nice to think about it as objects and attributes. Thanks, Namhyung > > I'm happy to look at doing the refactor to be similar to 'perf > list'/builtin-list.c. Namhyung I thought might have gotten to it with > his recent work on improving aggregation. If I hear silence then I'll > assume that is a request I do it :-) > > Pragmatically in the short term we could land your changes, but I > worry they are more of the whac-a-mole and something somewhere else > will break. Which is why we have a test, and so I'm not overly > worried. I can download and test too. > > Anyway, sorry for the issue and let me know what you think. Thanks, > Ian > > > > ========================= > > > > On machines that don't support topdown, the problem can be shown by > > doubling the following line in util/stat-shadow.c, so that the simple > > 'insn per cycle' metric is printed twice: > > > > print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio); > > > > The worst problem is that the JSON line is broken, such as: > > > > ... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit" > > : "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ... > > here ^^^^^ > > > > ========================= > > > > The first patch solves the JSON output correctness, the second tries > > to adjust the testcase to some extent, so that it should work on the > > topdown-capable machines. > > > > However, it's highly possible that the testcase will have to be fixed > > or maybe rewritten in future. First, it has quite naive evaluation of > > what's expected/correct/etc. Second, it does no JSON format validation > > at all. As a linter it should do so though. > > > > *** > > > > For further discussion: What about removing the check for number of > > expected elements in the line and just check for the keywords, such > > as "metric-value", "counter-value", "event", etc. and for some values > > that should be numeric. And, do proper JSON format sanity check? > > > > > > Thank you for inputs! > > > > Michael > > > > > > > > > > Michael Petlan (2): > > perf stat: Fix JSON metric printout for multiple metrics per line > > perf test: Fix JSON format linter test checks > > > > .../tests/shell/lib/perf_json_output_lint.py | 16 +++++------ > > tools/perf/util/stat-display.c | 28 +++++++++++-------- > > 2 files changed, 24 insertions(+), 20 deletions(-) > > > > -- > > 2.18.4 > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 0/2] perf test: Fix JSON linter 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers 2023-01-23 6:48 ` Namhyung Kim @ 2023-01-23 13:38 ` Arnaldo Carvalho de Melo 2023-01-24 17:39 ` Michael Petlan 2 siblings, 0 replies; 18+ messages in thread From: Arnaldo Carvalho de Melo @ 2023-01-23 13:38 UTC (permalink / raw) To: Ian Rogers Cc: Michael Petlan, Namhyung Kim, linux-perf-users, acme, qzhao, cjense Em Fri, Jan 20, 2023 at 09:37:33AM -0800, Ian Rogers escreveu: > On Fri, Jan 20, 2023 at 5:41 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > Hello all. > > > > We have observed issues with the 'perf stat JSON output linter' testcase > > on systems that allow topdown metrics. > > > > ========================= > > > > 1) The topdown metrics handling hardcodes printing more than one metric > > per line (refer to util/stat-shadow.c): > > > > if (retiring > 0.7 && heavy_ops > 0.1) > > color = PERF_COLOR_GREEN; > > print_metric(config, ctxp, color, "%8.1f%%", "Heavy Operations", > > heavy_ops * 100.); > > if (retiring > 0.7 && light_ops > 0.6) > > color = PERF_COLOR_GREEN; > > else > > color = NULL; > > print_metric(config, ctxp, color, "%8.1f%%", "Light Operations", > > light_ops * 100.); > > > > Thus, the test cannot rely on the fact that there will be only one > > metric per line. > > Right, these implicit metrics are also an issue with --metric-only. It > isn't clear from the command line flags when implicit and listed > metrics should be generated. The topdown events (Icelake+) made the > implicit metric problem worse, and they likely didn't exist or weren't > tested at the time of the json output. > > > 2) Since the JSON printing engine thinks that one and only one metric > > is printed, it always closes the line by adding '}'. This is not true, > > so I have fixed the comma printing and adjusted the engine to be > > capable of printing 1-N metrics and then close the line. > > So the current printing code is messy. For example, there is a newline > callback function, but that has little meaning for json where > everything is on a newline. For CSV mode, adding a summary used to > cause a column to suddenly appear on the left for the row containing > the summary. I believe the right thing to do is a refactor and > recently I did a similar refactor for 'perf list': > https://lore.kernel.org/lkml/20221114210723.2749751-11-irogers@google.com/ > So it is strange that metrics are "shadows" of events, but whatever > the point is to think about the printing API. In the change linked > above you can see that everytime something is printed the print > handling code is given all the information and the print handling code > has state. Based on the state and callback's information, the print > handling code can do nothing, properly format for CSV, json, etc. This > gets completely away from the kind of madness of branches and > whac-a-mole the code currently has. > > I'm happy to look at doing the refactor to be similar to 'perf > list'/builtin-list.c. Namhyung I thought might have gotten to it with > his recent work on improving aggregation. If I hear silence then I'll > assume that is a request I do it :-) Yeah, go for it :-) > Pragmatically in the short term we could land your changes, but I Ok, I saw Namhyung's Ack and will apply both, we can go from there. - Arnaldo > worry they are more of the whac-a-mole and something somewhere else > will break. Which is why we have a test, and so I'm not overly > worried. I can download and test too. > > Anyway, sorry for the issue and let me know what you think. Thanks, > Ian > > > > ========================= > > > > On machines that don't support topdown, the problem can be shown by > > doubling the following line in util/stat-shadow.c, so that the simple > > 'insn per cycle' metric is printed twice: > > > > print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio); > > > > The worst problem is that the JSON line is broken, such as: > > > > ... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit" > > : "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ... > > here ^^^^^ > > > > ========================= > > > > The first patch solves the JSON output correctness, the second tries > > to adjust the testcase to some extent, so that it should work on the > > topdown-capable machines. > > > > However, it's highly possible that the testcase will have to be fixed > > or maybe rewritten in future. First, it has quite naive evaluation of > > what's expected/correct/etc. Second, it does no JSON format validation > > at all. As a linter it should do so though. > > > > *** > > > > For further discussion: What about removing the check for number of > > expected elements in the line and just check for the keywords, such > > as "metric-value", "counter-value", "event", etc. and for some values > > that should be numeric. And, do proper JSON format sanity check? > > > > > > Thank you for inputs! > > > > Michael > > > > > > > > > > Michael Petlan (2): > > perf stat: Fix JSON metric printout for multiple metrics per line > > perf test: Fix JSON format linter test checks > > > > .../tests/shell/lib/perf_json_output_lint.py | 16 +++++------ > > tools/perf/util/stat-display.c | 28 +++++++++++-------- > > 2 files changed, 24 insertions(+), 20 deletions(-) > > > > -- > > 2.18.4 > > -- - Arnaldo ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 0/2] perf test: Fix JSON linter 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers 2023-01-23 6:48 ` Namhyung Kim 2023-01-23 13:38 ` Arnaldo Carvalho de Melo @ 2023-01-24 17:39 ` Michael Petlan 2023-01-25 0:37 ` Ian Rogers 2 siblings, 1 reply; 18+ messages in thread From: Michael Petlan @ 2023-01-24 17:39 UTC (permalink / raw) To: Ian Rogers; +Cc: Namhyung Kim, linux-perf-users, acme, acme, qzhao, cjense On Fri, 20 Jan 2023, Ian Rogers wrote: > On Fri, Jan 20, 2023 at 5:41 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > Hello all. > > > > We have observed issues with the 'perf stat JSON output linter' testcase > > on systems that allow topdown metrics. > > > > ========================= > > [...] > > 2) Since the JSON printing engine thinks that one and only one metric > > is printed, it always closes the line by adding '}'. This is not true, > > so I have fixed the comma printing and adjusted the engine to be > > capable of printing 1-N metrics and then close the line. > > So the current printing code is messy. For example, there is a newline > callback function, but that has little meaning for json where > everything is on a newline. For CSV mode, adding a summary used to > cause a column to suddenly appear on the left for the row containing > the summary. I believe the right thing to do is a refactor and > recently I did a similar refactor for 'perf list': > https://lore.kernel.org/lkml/20221114210723.2749751-11-irogers@google.com/ > So it is strange that metrics are "shadows" of events, but whatever > the point is to think about the printing API. In the change linked > above you can see that everytime something is printed the print > handling code is given all the information and the print handling code > has state. Based on the state and callback's information, the print > handling code can do nothing, properly format for CSV, json, etc. This > gets completely away from the kind of madness of branches and > whac-a-mole the code currently has. > > I'm happy to look at doing the refactor to be similar to 'perf > list'/builtin-list.c. Namhyung I thought might have gotten to it with > his recent work on improving aggregation. If I hear silence then I'll > assume that is a request I do it :-) > > Pragmatically in the short term we could land your changes, but I > worry they are more of the whac-a-mole and something somewhere else > will break. Which is why we have a test, and so I'm not overly > worried. I can download and test too. > > Anyway, sorry for the issue and let me know what you think. Thanks, > Ian Hello. I think that applying the patchset won't make things worse, eventhough we know it would deserve a better solution for the whole print engine. Yes, we have a test, but maybe that's what should be improved first, since it does not actually verify the format correctness. I have hit the problem because of failing test, but the fail cause was that there were too many commas, but strings like "Heavy Operations"}"metric-value" are still OK according to the linter. Proper JSON linter might be in some library, but we don't want to add too many dependencies I guess. Maybe some simple JSON linter I used when preparing the patchset would be enough for our perf-stat output... I'll convert it to Python and post it to see. ============================= Finally, speaking of tests, I think that thinking of integrating the external perf testsuite [1] might be a better approach than adding new shell-based tests such as "perf stat tests", etc. Tests like that have been already written, see [1]. Some years ago, I was trying to add it to perf-test, however it was unsuccessful, but since then, many shell-based tests were added instead and I think they slightly duplicate the work already done. Thoughts? Michael [1] https://github.com/rfmvh/perftool-testsuite > > > > ========================= > > > > On machines that don't support topdown, the problem can be shown by > > doubling the following line in util/stat-shadow.c, so that the simple > > 'insn per cycle' metric is printed twice: > > > > print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio); > > > > The worst problem is that the JSON line is broken, such as: > > > > ... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit" > > : "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ... > > here ^^^^^ > > > > ========================= > > > > The first patch solves the JSON output correctness, the second tries > > to adjust the testcase to some extent, so that it should work on the > > topdown-capable machines. > > > > However, it's highly possible that the testcase will have to be fixed > > or maybe rewritten in future. First, it has quite naive evaluation of > > what's expected/correct/etc. Second, it does no JSON format validation > > at all. As a linter it should do so though. > > > > *** > > > > For further discussion: What about removing the check for number of > > expected elements in the line and just check for the keywords, such > > as "metric-value", "counter-value", "event", etc. and for some values > > that should be numeric. And, do proper JSON format sanity check? > > > > > > Thank you for inputs! > > > > Michael > > > > > > > > > > Michael Petlan (2): > > perf stat: Fix JSON metric printout for multiple metrics per line > > perf test: Fix JSON format linter test checks > > > > .../tests/shell/lib/perf_json_output_lint.py | 16 +++++------ > > tools/perf/util/stat-display.c | 28 +++++++++++-------- > > 2 files changed, 24 insertions(+), 20 deletions(-) > > > > -- > > 2.18.4 > > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [PATCH 0/2] perf test: Fix JSON linter 2023-01-24 17:39 ` Michael Petlan @ 2023-01-25 0:37 ` Ian Rogers 0 siblings, 0 replies; 18+ messages in thread From: Ian Rogers @ 2023-01-25 0:37 UTC (permalink / raw) To: Michael Petlan; +Cc: Namhyung Kim, linux-perf-users, acme, acme, qzhao, cjense On Tue, Jan 24, 2023 at 9:39 AM Michael Petlan <mpetlan@redhat.com> wrote: > > On Fri, 20 Jan 2023, Ian Rogers wrote: > > On Fri, Jan 20, 2023 at 5:41 AM Michael Petlan <mpetlan@redhat.com> wrote: > > > > > > Hello all. > > > > > > We have observed issues with the 'perf stat JSON output linter' testcase > > > on systems that allow topdown metrics. > > > > > > ========================= > > > > [...] > > > 2) Since the JSON printing engine thinks that one and only one metric > > > is printed, it always closes the line by adding '}'. This is not true, > > > so I have fixed the comma printing and adjusted the engine to be > > > capable of printing 1-N metrics and then close the line. > > > > So the current printing code is messy. For example, there is a newline > > callback function, but that has little meaning for json where > > everything is on a newline. For CSV mode, adding a summary used to > > cause a column to suddenly appear on the left for the row containing > > the summary. I believe the right thing to do is a refactor and > > recently I did a similar refactor for 'perf list': > > https://lore.kernel.org/lkml/20221114210723.2749751-11-irogers@google.com/ > > So it is strange that metrics are "shadows" of events, but whatever > > the point is to think about the printing API. In the change linked > > above you can see that everytime something is printed the print > > handling code is given all the information and the print handling code > > has state. Based on the state and callback's information, the print > > handling code can do nothing, properly format for CSV, json, etc. This > > gets completely away from the kind of madness of branches and > > whac-a-mole the code currently has. > > > > I'm happy to look at doing the refactor to be similar to 'perf > > list'/builtin-list.c. Namhyung I thought might have gotten to it with > > his recent work on improving aggregation. If I hear silence then I'll > > assume that is a request I do it :-) > > > > Pragmatically in the short term we could land your changes, but I > > worry they are more of the whac-a-mole and something somewhere else > > will break. Which is why we have a test, and so I'm not overly > > worried. I can download and test too. > > > > Anyway, sorry for the issue and let me know what you think. Thanks, > > Ian > > Hello. > > I think that applying the patchset won't make things worse, eventhough > we know it would deserve a better solution for the whole print engine. > > Yes, we have a test, but maybe that's what should be improved first, > since it does not actually verify the format correctness. I have hit > the problem because of failing test, but the fail cause was that there > were too many commas, but strings like > > "Heavy Operations"}"metric-value" > > are still OK according to the linter. > > Proper JSON linter might be in some library, but we don't want to add > too many dependencies I guess. > > Maybe some simple JSON linter I used when preparing the patchset would > be enough for our perf-stat output... I'll convert it to Python and > post it to see. I've been trying to tidy up the libraries under tools/lib recently, and their build. I'm hoping that with this we can have more statically built in libraries rather than a big monolithic application. In part for testing reasons, but also separation of concerns and the like. Fwiw, we did have a json reader library from jsmn in the pmu-events jevents.c code in the past. As it was never updated and had become forked, I wasn't a huge fan of it. > ============================= > > Finally, speaking of tests, I think that thinking of integrating the > external perf testsuite [1] might be a better approach than adding > new shell-based tests such as "perf stat tests", etc. Tests like that > have been already written, see [1]. > > Some years ago, I was trying to add it to perf-test, however it was > unsuccessful, but since then, many shell-based tests were added > instead and I think they slightly duplicate the work already done. > > Thoughts? > Michael > > [1] https://github.com/rfmvh/perftool-testsuite As someone who maintains a build, I'd love to see all of the perf testing in the kernel tree :-) What do you think would be the best strategy to integrate the test suite? Perhaps create a new directory under perf/tools/tests/shell, add the tests there and then add a wrapper shell script that invokes them all as one large shell test. From this we can work to have smaller tests, better output within perf test, etc. I think it'd be best for you to do an initial push, but I'd be willing to help from then on. Thanks, Ian > > > > > > > ========================= > > > > > > On machines that don't support topdown, the problem can be shown by > > > doubling the following line in util/stat-shadow.c, so that the simple > > > 'insn per cycle' metric is printed twice: > > > > > > print_metric(config, ctxp, NULL, "%7.2f ", "insn per cycle", ratio); > > > > > > The worst problem is that the JSON line is broken, such as: > > > > > > ... "pcnt-running" : 100.00, "metric-value" : 3.501931, "metric-unit" > > > : "Heavy Operations"}"metric-value" : 14.007787, "metric-unit" : ... > > > here ^^^^^ > > > > > > ========================= > > > > > > The first patch solves the JSON output correctness, the second tries > > > to adjust the testcase to some extent, so that it should work on the > > > topdown-capable machines. > > > > > > However, it's highly possible that the testcase will have to be fixed > > > or maybe rewritten in future. First, it has quite naive evaluation of > > > what's expected/correct/etc. Second, it does no JSON format validation > > > at all. As a linter it should do so though. > > > > > > *** > > > > > > For further discussion: What about removing the check for number of > > > expected elements in the line and just check for the keywords, such > > > as "metric-value", "counter-value", "event", etc. and for some values > > > that should be numeric. And, do proper JSON format sanity check? > > > > > > > > > Thank you for inputs! > > > > > > Michael > > > > > > > > > > > > > > > Michael Petlan (2): > > > perf stat: Fix JSON metric printout for multiple metrics per line > > > perf test: Fix JSON format linter test checks > > > > > > .../tests/shell/lib/perf_json_output_lint.py | 16 +++++------ > > > tools/perf/util/stat-display.c | 28 +++++++++++-------- > > > 2 files changed, 24 insertions(+), 20 deletions(-) > > > > > > -- > > > 2.18.4 > > > > > > > > ^ permalink raw reply [flat|nested] 18+ messages in thread
end of thread, other threads:[~2023-06-06 11:17 UTC | newest] Thread overview: 18+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2023-01-20 13:40 [PATCH 0/2] perf test: Fix JSON linter Michael Petlan 2023-01-20 13:40 ` [PATCH 1/2] perf stat: Fix JSON metric printout for multiple metrics per line Michael Petlan 2023-01-23 6:31 ` Namhyung Kim 2023-05-22 12:11 ` Michael Petlan 2023-06-06 11:16 ` Michael Petlan 2023-01-20 13:40 ` [PATCH 2/2] perf test: Fix JSON format linter test checks Michael Petlan 2023-01-23 6:36 ` Namhyung Kim 2023-01-24 16:49 ` Michael Petlan 2023-01-24 17:26 ` Namhyung Kim 2023-01-27 12:26 ` Arnaldo Carvalho de Melo 2023-01-27 12:30 ` Arnaldo Carvalho de Melo 2023-01-31 17:14 ` Michael Petlan 2023-02-02 1:18 ` Arnaldo Carvalho de Melo 2023-01-20 17:37 ` [PATCH 0/2] perf test: Fix JSON linter Ian Rogers 2023-01-23 6:48 ` Namhyung Kim 2023-01-23 13:38 ` Arnaldo Carvalho de Melo 2023-01-24 17:39 ` Michael Petlan 2023-01-25 0:37 ` Ian Rogers
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).