Re: [PATCH] perf/stat: Handle different PMU names with common prefix

From: SÃbastien Boisvert
Date: Fri Oct 26 2018 - 11:04:50 EST


On 2018-10-23 11:16 a.m., Thomas Richter wrote:
> On s390 the CPU Measurement Facility for counters now supports
> 2 PMUs named cpum_cf (CPU Measurement Facility for counters) and
> cpum_cf_diag (CPU Measurement Facility for diagnostic counters)
> for one and the same CPU.
>
> Running command
>
> [root@s35lp76 perf]# ./perf stat -e tx_c_tend \
> -- ~/mytests/cf-tx-events 1
>

Is tx_c_tend related to these ?

tx-abort OR cpu/tx-abort/ [Kernel PMU event]
tx-capacity OR cpu/tx-capacity/ [Kernel PMU event]
tx-commit OR cpu/tx-commit/ [Kernel PMU event]
tx-conflict OR cpu/tx-conflict/ [Kernel PMU event]
tx-start OR cpu/tx-start/ [Kernel PMU event]


> Measuring transactions
> TX_C_TABORT_NO_SPECIAL: 0 expected:0
> TX_C_TABORT_SPECIAL: 0 expected:0
> TX_C_TEND: 1 expected:1
> TX_NC_TABORT: 11 expected:11
> TX_NC_TEND: 1 expected:1
>
> Performance counter stats for '/root/mytests/cf-tx-events 1':
>
> 2 tx_c_tend
>
> 0.002120091 seconds time elapsed
>
> 0.000121000 seconds user
> 0.002127000 seconds sys
>
> [root@s35lp76 perf]#
>
> displays output which is unexpected (and wrong):
>
> 2 tx_c_tend
>
> The test program definitely triggers only one transaction, as shown
> in line 'TX_C_TEND: 1 expected:1'.

OK, something is done twice in perf stat, but should be done once.

>
> This is caused by the following call sequence:
>
> pmu_lookup() scans and installs a PMU.
> +--> pmu_aliases() parses all aliases in directory
> .../<pmu-name>/events/* which are file names.
> +--> pmu_aliases_parse() Read each file in directory and create
> an new alias entry. This is done with
> +--> perf_pmu__new_alias() and
> +--> __perf_pmu__new_alias() which also check for
> identical alias names.
>
> After pmu_aliases() returns, a complete list of event names
> for this pmu has been created. Now function
>
> pmu_add_cpu_aliases() is called to add the events listed in the json
> | files to the alias list of the cpu.
> +--> perf_pmu__find_map() Returns a pointer to the json events.
>
> Now function pmu_add_cpu_aliases() scans through all events listed
> in the JSON files for this CPU.

Are these JSON files temporary in nature ?

> Each json event pmu name is compared with the current PMU being
> built up and if they mismatch, the json event is added to the
> current PMUs alias list.
> To avoid duplicate entries the following comparison is done:
>
> if (!is_arm_pmu_core(name)) {
> pname = pe->pmu ? pe->pmu : "cpu";
> if (strncmp(pname, name, strlen(pname)))
> continue;
> }

Is this the test to know whether a PMU event must be added or not ?

>
> The culprit is the strncmp() function.
>
> Using current s390 PMU naming, the first PMU is 'cpum_cf'
> and a long list of events is added, among them 'tx_c_tend'
>
> When the second PMU named 'cpum_cf_diag' is added, only one event
> named 'CF_DIAG' is added by the pmu_aliases() function.
>
> Now function pmu_add_cpu_aliases() is invoked for PMU 'cpum_cf_diag'.
> Since the CPUID string is the same for both PMUs, json file events
> for PMU named 'cpum_cf' are added to the PMU 'cpm_cf_diag'
>
> This happens because the strncmp() actually compares:
>> strncmp("cpum_cf", "cpum_cf_diag", 6);

I fail to see how these argument values can be generated by this code:

pname = pe->pmu ? pe->pmu : "cpu";
if (strncmp(pname, name, strlen(pname)))

The 3rd argument is the length of the first argument, pname.

With "cpum_cf", it should be 7, not 6.



>
> The first parameter is the pmu name taken from the event in
> the json file. The second parameter is the pmu name of the PMU
> currently being built.
> They are different, but the length of the compare only tests the
> common prefix and this returns 0(true) when it should return false.
>

The 6 comes from strlen(pname). In that case, it is neither the length of
"cpum_cf" (7) or "cpum_cf_diag" (12).

> Now all events for PMU cpum_cf are added to the alias list for pmu
> cpum_cf_diag.
>
> Later on in function parse_events_add_pmu() the event 'tx_c_end' is
> searched in all available PMUs and found twice, adding it two
> times to the evsel_list global variable which is the root
> of all events. This results in a counter value of 2 instead
> of 1.

The counter value of 2 is 1 + 1 since both PMU events 'tx_c_end' that
were added got a +1.

>
> Output with this patch:
>
> [root@s35lp76 perf]# ./perf stat -e tx_c_tend \
> -- ~/mytests/cf-tx-events 1
> Measuring transactions
> TX_C_TABORT_NO_SPECIAL: 0 expected:0
> TX_C_TABORT_SPECIAL: 0 expected:0
> TX_C_TEND: 1 expected:1
> TX_NC_TABORT: 11 expected:11
> TX_NC_TEND: 1 expected:1
>
> Performance counter stats for '/root/mytests/cf-tx-events 1':
>
> 1 tx_c_tend
>

OK, now that's 1, like in your expected test value:

TX_C_TEND: 1 expected:1

> 0.001815365 seconds time elapsed
>
> 0.000123000 seconds user
> 0.001756000 seconds sys
>
> [root@s35lp76 perf]#
>
> Fixes: 292c34c10249 ("perf pmu: Fix core PMU alias list for X86 platform")
> Signed-off-by: Thomas Richter <tmricht@xxxxxxxxxxxxx>
> Reviewed-by: Hendrik Brueckner <brueckner@xxxxxxxxxxxxx>
> Cc: Kan Liang <kan.liang@xxxxxxxxxxxxxxx>
> Cc: <stable@xxxxxxxxxxxxxxx> # 4.18+
> ---
> tools/perf/util/pmu.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
> index 7799788f662f..7e49baad304d 100644
> --- a/tools/perf/util/pmu.c
> +++ b/tools/perf/util/pmu.c
> @@ -773,7 +773,7 @@ static void pmu_add_cpu_aliases(struct list_head *head, struct perf_pmu *pmu)
>
> if (!is_arm_pmu_core(name)) {
> pname = pe->pmu ? pe->pmu : "cpu";
> - if (strncmp(pname, name, strlen(pname)))
> + if (strcmp(pname, name))
> continue;
> }
>
>