[PATCH v1 1/2] perf tsc: Add missing newlines to debug statements

[PATCH v1 1/2] perf tsc: Add missing newlines to debug statements

[Ian Rogers]

It is assumed that debug statements always print a newline, fix two
missing ones.

Signed-off-by: Ian Rogers <irogers@google.com>
---
This patch was inspired by bad debug output in:
https://lore.kernel.org/linux-perf-users/CAGjhMsg_bVKJ_zfsLUR32+oZwGDr3OiBHV_BJ3QtFjyKAs7Sgg@mail.gmail.com/
---
 tools/perf/arch/x86/util/tsc.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tools/perf/arch/x86/util/tsc.c b/tools/perf/arch/x86/util/tsc.c
index 9b99f48b923c..e2d6cfe21057 100644
--- a/tools/perf/arch/x86/util/tsc.c
+++ b/tools/perf/arch/x86/util/tsc.c
@@ -33,7 +33,7 @@ static double cpuinfo_tsc_freq(void)
 
 	cpuinfo = fopen("/proc/cpuinfo", "r");
 	if (!cpuinfo) {
-		pr_err("Failed to read /proc/cpuinfo for TSC frequency");
+		pr_err("Failed to read /proc/cpuinfo for TSC frequency\n");
 		return NAN;
 	}
 	while (getline(&line, &len, cpuinfo) > 0) {
@@ -48,7 +48,7 @@ static double cpuinfo_tsc_freq(void)
 	}
 out:
 	if (fpclassify(result) == FP_ZERO)
-		pr_err("Failed to find TSC frequency in /proc/cpuinfo");
+		pr_err("Failed to find TSC frequency in /proc/cpuinfo\n");
 
 	free(line);
 	fclose(cpuinfo);
-- 
2.43.0.429.g432eaa2c6b-goog

[PATCH v1 2/2] perf parse-events: Improve error location of terms cloned from an event

[Ian Rogers]

A PMU event/alias will have a set of format terms that replace it when
an event is parsed. The location of the terms is their position when
parsed for the event/alias either from sysfs or json. This location is
of little use when an event fails to parse as the error will be given
in terms of the location in the string of events parsed not the json
or sysfs string. Fix this by making the cloned terms location that of
the event/alias.

If a cloned term from an event/alias is invalid the bad format is hard
to determine from the error string. Add the name of the bad format
into the error string.

Signed-off-by: Ian Rogers <irogers@google.com>
---
These fixes were inspired by the poor error output in:
https://lore.kernel.org/linux-perf-users/alpine.LRH.2.20.2401300733310.11354@Diego/
---
 tools/perf/util/pmu.c | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
index 355f813f960d..437386dedd5c 100644
--- a/tools/perf/util/pmu.c
+++ b/tools/perf/util/pmu.c
@@ -657,7 +657,7 @@ static int pmu_aliases_parse(struct perf_pmu *pmu)
 	return 0;
 }
 
-static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms)
+static int pmu_alias_terms(struct perf_pmu_alias *alias, int err_loc, struct list_head *terms)
 {
 	struct parse_events_term *term, *cloned;
 	struct parse_events_terms clone_terms;
@@ -675,6 +675,7 @@ static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms
 		 * which we don't want for implicit terms in aliases.
 		 */
 		cloned->weak = true;
+		cloned->err_term = cloned->err_val = err_loc;
 		list_add_tail(&cloned->list, &clone_terms.terms);
 	}
 	list_splice_init(&clone_terms.terms, terms);
@@ -1363,8 +1364,8 @@ static int pmu_config_term(const struct perf_pmu *pmu,
 
 			parse_events_error__handle(err, term->err_val,
 				asprintf(&err_str,
-				    "value too big for format, maximum is %llu",
-				    (unsigned long long)max_val) < 0
+				    "value too big for format (%s), maximum is %llu",
+				    format->name, (unsigned long long)max_val) < 0
 				    ? strdup("value too big for format")
 				    : err_str,
 				    NULL);
@@ -1518,7 +1519,7 @@ int perf_pmu__check_alias(struct perf_pmu *pmu, struct parse_events_terms *head_
 		alias = pmu_find_alias(pmu, term);
 		if (!alias)
 			continue;
-		ret = pmu_alias_terms(alias, &term->list);
+		ret = pmu_alias_terms(alias, term->err_term, &term->list);
 		if (ret) {
 			parse_events_error__handle(err, term->err_term,
 						strdup("Failure to duplicate terms"),
-- 
2.43.0.429.g432eaa2c6b-goog

Re: [PATCH v1 2/2] perf parse-events: Improve error location of terms cloned from an event

[James Clark]

On 31/01/2024 06:30, Ian Rogers wrote:
> A PMU event/alias will have a set of format terms that replace it when
> an event is parsed. The location of the terms is their position when
> parsed for the event/alias either from sysfs or json. This location is
> of little use when an event fails to parse as the error will be given
> in terms of the location in the string of events parsed not the json
> or sysfs string. Fix this by making the cloned terms location that of
> the event/alias.
> 
> If a cloned term from an event/alias is invalid the bad format is hard
> to determine from the error string. Add the name of the bad format
> into the error string.
> 
> Signed-off-by: Ian Rogers <irogers@google.com>
> ---
> These fixes were inspired by the poor error output in:
> https://lore.kernel.org/linux-perf-users/alpine.LRH.2.20.2401300733310.11354@Diego/
> ---
>  tools/perf/util/pmu.c | 9 +++++----
>  1 file changed, 5 insertions(+), 4 deletions(-)
> 
> diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
> index 355f813f960d..437386dedd5c 100644
> --- a/tools/perf/util/pmu.c
> +++ b/tools/perf/util/pmu.c
> @@ -657,7 +657,7 @@ static int pmu_aliases_parse(struct perf_pmu *pmu)
>  	return 0;
>  }
>  
> -static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms)
> +static int pmu_alias_terms(struct perf_pmu_alias *alias, int err_loc, struct list_head *terms)
>  {
>  	struct parse_events_term *term, *cloned;
>  	struct parse_events_terms clone_terms;
> @@ -675,6 +675,7 @@ static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms
>  		 * which we don't want for implicit terms in aliases.
>  		 */
>  		cloned->weak = true;
> +		cloned->err_term = cloned->err_val = err_loc;
>  		list_add_tail(&cloned->list, &clone_terms.terms);
>  	}
>  	list_splice_init(&clone_terms.terms, terms);
> @@ -1363,8 +1364,8 @@ static int pmu_config_term(const struct perf_pmu *pmu,
>  
>  			parse_events_error__handle(err, term->err_val,
>  				asprintf(&err_str,
> -				    "value too big for format, maximum is %llu",
> -				    (unsigned long long)max_val) < 0
> +				    "value too big for format (%s), maximum is %llu",
> +				    format->name, (unsigned long long)max_val) < 0
>  				    ? strdup("value too big for format")
>  				    : err_str,
>  				    NULL);

Hi Ian,

I went to test this, but since b30d4f0b6954 ("perf parse-events:
Additional error reporting") I don't get this size error message
anymore, just a "bad event/PMU not found" type error. I'm not sure if
this is something Arm specific, or you're seeing the same thing?

Before b30d4f0b6954:

  $ perf record -e bus_access_rd/long=2
  event syntax error: '..ss_rd/long=2/'
                                  \___ value too big for format, maximum
                                       is 1

  Initial error:
  event syntax error: 'bus_access_rd/long=2/'
                     \___ Cannot find PMU `bus_access_rd'. Missing
                          kernel support?
  Run 'perf list' for a list of valid events

   Usage: perf record [<options>] [<command>]
    or: perf record [<options>] -- <command> [<options>]

    -e, --event <event>   event selector. use 'perf list' to list
      available events

After b30d4f0b6954:

  $ perf record -e bus_access_rd/long=2
  event syntax error: '..ss_rd/long=2/'
                                  \___ Bad event or PMU

  Unabled to find PMU or event on a PMU of 'bus_access_rd'

  Initial error:
  event syntax error: 'bus_access_rd/long=2/'
                     \___ Cannot find PMU `bus_access_rd'. Missing
                          kernel support?

  Run 'perf list' for a list of valid events

   Usage: perf record [<options>] [<command>]
    or: perf record [<options>] -- <command> [<options>]

    -e, --event <event>   event selector. use 'perf list' to list
      available events

Re: [PATCH v1 2/2] perf parse-events: Improve error location of terms cloned from an event

[Ian Rogers]

On Wed, Jan 31, 2024 at 3:49 AM James Clark <james.clark@arm.com> wrote:
>
>
>
> On 31/01/2024 06:30, Ian Rogers wrote:
> > A PMU event/alias will have a set of format terms that replace it when
> > an event is parsed. The location of the terms is their position when
> > parsed for the event/alias either from sysfs or json. This location is
> > of little use when an event fails to parse as the error will be given
> > in terms of the location in the string of events parsed not the json
> > or sysfs string. Fix this by making the cloned terms location that of
> > the event/alias.
> >
> > If a cloned term from an event/alias is invalid the bad format is hard
> > to determine from the error string. Add the name of the bad format
> > into the error string.
> >
> > Signed-off-by: Ian Rogers <irogers@google.com>
> > ---
> > These fixes were inspired by the poor error output in:
> > https://lore.kernel.org/linux-perf-users/alpine.LRH.2.20.2401300733310.11354@Diego/
> > ---
> >  tools/perf/util/pmu.c | 9 +++++----
> >  1 file changed, 5 insertions(+), 4 deletions(-)
> >
> > diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
> > index 355f813f960d..437386dedd5c 100644
> > --- a/tools/perf/util/pmu.c
> > +++ b/tools/perf/util/pmu.c
> > @@ -657,7 +657,7 @@ static int pmu_aliases_parse(struct perf_pmu *pmu)
> >       return 0;
> >  }
> >
> > -static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms)
> > +static int pmu_alias_terms(struct perf_pmu_alias *alias, int err_loc, struct list_head *terms)
> >  {
> >       struct parse_events_term *term, *cloned;
> >       struct parse_events_terms clone_terms;
> > @@ -675,6 +675,7 @@ static int pmu_alias_terms(struct perf_pmu_alias *alias, struct list_head *terms
> >                * which we don't want for implicit terms in aliases.
> >                */
> >               cloned->weak = true;
> > +             cloned->err_term = cloned->err_val = err_loc;
> >               list_add_tail(&cloned->list, &clone_terms.terms);
> >       }
> >       list_splice_init(&clone_terms.terms, terms);
> > @@ -1363,8 +1364,8 @@ static int pmu_config_term(const struct perf_pmu *pmu,
> >
> >                       parse_events_error__handle(err, term->err_val,
> >                               asprintf(&err_str,
> > -                                 "value too big for format, maximum is %llu",
> > -                                 (unsigned long long)max_val) < 0
> > +                                 "value too big for format (%s), maximum is %llu",
> > +                                 format->name, (unsigned long long)max_val) < 0
> >                                   ? strdup("value too big for format")
> >                                   : err_str,
> >                                   NULL);
>
> Hi Ian,
>
> I went to test this, but since b30d4f0b6954 ("perf parse-events:
> Additional error reporting") I don't get this size error message
> anymore, just a "bad event/PMU not found" type error. I'm not sure if
> this is something Arm specific, or you're seeing the same thing?
>
> Before b30d4f0b6954:
>
>   $ perf record -e bus_access_rd/long=2
>   event syntax error: '..ss_rd/long=2/'
>                                   \___ value too big for format, maximum
>                                        is 1
>
>   Initial error:
>   event syntax error: 'bus_access_rd/long=2/'
>                      \___ Cannot find PMU `bus_access_rd'. Missing
>                           kernel support?
>   Run 'perf list' for a list of valid events
>
>    Usage: perf record [<options>] [<command>]
>     or: perf record [<options>] -- <command> [<options>]
>
>     -e, --event <event>   event selector. use 'perf list' to list
>       available events
>
> After b30d4f0b6954:
>
>   $ perf record -e bus_access_rd/long=2
>   event syntax error: '..ss_rd/long=2/'
>                                   \___ Bad event or PMU
>
>   Unabled to find PMU or event on a PMU of 'bus_access_rd'
>
>   Initial error:
>   event syntax error: 'bus_access_rd/long=2/'
>                      \___ Cannot find PMU `bus_access_rd'. Missing
>                           kernel support?
>
>   Run 'perf list' for a list of valid events
>
>    Usage: perf record [<options>] [<command>]
>     or: perf record [<options>] -- <command> [<options>]
>
>     -e, --event <event>   event selector. use 'perf list' to list
>       available events
>

Hi James, this is a different case. Here you have bus_access_rd being
matched as a wildcard event or PMU. This is done here:
https://git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next.git/tree/tools/perf/util/parse-events.y?h=perf-tools-next#n318
The "long=2" is a term to be applied to that event, its index is
passed through from the yacc code and not cloned from the original
sysfs/json event (which this patch modifies). Doing something similar
to your test on x86 I see:

```
$ perf stat -e 'slots/edge=2/' true
event syntax error: 'slots/edge=2/'
                               \___ Bad event or PMU

Unable to find PMU or event on a PMU of 'slots'

Initial error:
event syntax error: 'slots/edge=2/'
                    \___ Cannot find PMU `slots'. Missing kernel support?
Run 'perf list' for a list of valid events

Usage: perf stat [<options>] [<command>]

   -e, --event <event>   event selector. use 'perf list' to list
available events
```

The string indexes look correct, but in the mail here they look wonky
due to not having a fixed width font. The error message isn't the best
and -vv reveals why:

```
$ perf stat -vv -e 'slots/edge=2/' true
Using CPUID GenuineIntel-6-8D-1
Attempt to add: cpu/edge=0x2,slots/
..after resolving event: cpu/edge=0x2,event=0,umask=0x4/
Multiple errors dropping message: value too big for format (edge),
maximum is 1 (<no help>)
event syntax error: 'slots/edge=2/'
                               \___ Bad event or PMU

Unable to find PMU or event on a PMU of 'slots'

Initial error:
event syntax error: 'slots/edge=2/'
                    \___ Cannot find PMU `slots'. Missing kernel support?
Run 'perf list' for a list of valid events

Usage: perf stat [<options>] [<command>]

   -e, --event <event>   event selector. use 'perf list' to list
available events
```

The dropped help message is the most useful. I've written a patch to
keep all errors in a list and dump them all on failure. I'll send a v2
patch with that added. The output looks like:

```
$ perf stat -e 'slots/edge=2/' true
event syntax error: 'slots/edge=2/'
                    \___ Bad event or PMU

Unable to find PMU or event on a PMU of 'slots'
event syntax error: 'slots/edge=2/'
                               \___ value too big for format (edge),
maximum is 1
event syntax error: 'slots/edge=2/'
                    \___ Cannot find PMU `slots'. Missing kernel support?
Run 'perf list' for a list of valid events

Usage: perf stat [<options>] [<command>]

   -e, --event <event>   event selector. use 'perf list' to list
available events
```

Thanks,
Ian

Re: [PATCH v1 1/2] perf tsc: Add missing newlines to debug statements

[James Clark]

On 31/01/2024 06:30, Ian Rogers wrote:
> It is assumed that debug statements always print a newline, fix two
> missing ones.
> 
> Signed-off-by: Ian Rogers <irogers@google.com>
> ---
> This patch was inspired by bad debug output in:
> https://lore.kernel.org/linux-perf-users/CAGjhMsg_bVKJ_zfsLUR32+oZwGDr3OiBHV_BJ3QtFjyKAs7Sgg@mail.gmail.com/
> ---
>  tools/perf/arch/x86/util/tsc.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/tools/perf/arch/x86/util/tsc.c b/tools/perf/arch/x86/util/tsc.c
> index 9b99f48b923c..e2d6cfe21057 100644
> --- a/tools/perf/arch/x86/util/tsc.c
> +++ b/tools/perf/arch/x86/util/tsc.c
> @@ -33,7 +33,7 @@ static double cpuinfo_tsc_freq(void)
>  
>  	cpuinfo = fopen("/proc/cpuinfo", "r");
>  	if (!cpuinfo) {
> -		pr_err("Failed to read /proc/cpuinfo for TSC frequency");
> +		pr_err("Failed to read /proc/cpuinfo for TSC frequency\n");
>  		return NAN;
>  	}
>  	while (getline(&line, &len, cpuinfo) > 0) {
> @@ -48,7 +48,7 @@ static double cpuinfo_tsc_freq(void)
>  	}
>  out:
>  	if (fpclassify(result) == FP_ZERO)
> -		pr_err("Failed to find TSC frequency in /proc/cpuinfo");
> +		pr_err("Failed to find TSC frequency in /proc/cpuinfo\n");
>  
>  	free(line);
>  	fclose(cpuinfo);


Reviewed-by: James Clark <james.clark@arm.com>