Message-ID: <Z1HHClaOwjJnR5gr@x1>
Date: Thu, 5 Dec 2024 12:30:18 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Namhyung Kim <namhyung@...nel.org>
Cc: Oliver Sang <oliver.sang@...el.com>, oe-lkp@...ts.linux.dev,
	lkp@...el.com, linux-kernel@...r.kernel.org,
	James Clark <james.clark@...aro.org>,
	Ravi Bangoria <ravi.bangoria@....com>,
	Kan Liang <kan.liang@...ux.intel.com>,
	James Clark <james.clark@....com>,
	Atish Patra <atishp@...shpatra.org>,
	Mingwei Zhang <mizhang@...gle.com>,
	Kajol Jain <kjain@...ux.ibm.com>,
	Thomas Richter <tmricht@...ux.ibm.com>,
	Palmer Dabbelt <palmer@...osinc.com>,
	linux-perf-users@...r.kernel.org
Subject: Re: [linus:master] [perf tools]  af954f76ee:
 perf-sanity-tests.Test_data_symbol.fail

On Wed, Dec 04, 2024 at 02:21:06PM -0800, Namhyung Kim wrote:
> On Wed, Dec 04, 2024 at 01:44:06PM -0800, Namhyung Kim wrote:
> [SNIP]
> >   perf_event_attr:
> >     type                             4 (cpu)
> >     size                             136
> >     config                           0x1cd (mem-loads)
> >     { sample_period, sample_freq }   4000
> >     sample_type                      IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT
> >     read_format                      ID|LOST
> >     freq                             1
> >     precise_ip                       3
> >     sample_id_all                    1
> >     { bp_addr, config1 }             0x1f
> >   ------------------------------------------------------------
> >   sys_perf_event_open: pid -1  cpu 0  group_fd 5  flags 0x8
> >   sys_perf_event_open failed, error -22
> >   Using PERF_SAMPLE_READ / :S modifier is not compatible with inherit, falling back to no-inherit.
> >   Error:
> >   The sys_perf_event_open() syscall returned with 22 (Invalid argument) for event (cpu/mem-loads,ldlat=30/).
> >   "dmesg | grep -i perf" may provide additional information.
> > 
> > There's an issue with fallback on the inherit bit with the sample read.
> > I'll take a look.
> 
> Hmm, no.  It doesn't have neight SAMPLE_READ nor inherit.  So the error
> message was misleading.  Maybe it should be printed when it actually
> clears the bits.
> 
> Anyway, I've tested with the old code and realzed that it might be due
> to precise_ip being 3.  I expected it'd return EOPNOTSUPP for the case
> but it seems to return EINVAL sometimes.  Then it should check it after
> the missing features like below.  Can you please test?

Before:

root@...ber:/tmp# perf mem record -a sleep 1s
Error:
The sys_perf_event_open() syscall returned with 22 (Invalid argument) for event (cpu_core/mem-loads,ldlat=30/).
"dmesg | grep -i perf" may provide additional information.

root@...ber:/tmp# 

With your patch:

root@...ber:/tmp# perf mem record -a sleep 1s
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 11.211 MB perf.data (14616 samples) ]
root@...ber:/tmp# perf evlist
cpu_atom/mem-loads,ldlat=30/P
cpu_atom/mem-stores/P
cpu_core/mem-loads-aux/
cpu_core/mem-loads,ldlat=30/
cpu_core/mem-stores/P
dummy:u
# Tip: use 'perf evlist -g' to show group information
root@...ber:/tmp# perf evlist -v
cpu_atom/mem-loads,ldlat=30/P: type: 10 (cpu_atom), size: 136, config: 0x5d0 (mem-loads), { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, disabled: 1, freq: 1, precise_ip: 3, sample_id_all: 1, { bp_addr, config1 }: 0x1f
cpu_atom/mem-stores/P: type: 10 (cpu_atom), size: 136, config: 0x6d0 (mem-stores), { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, disabled: 1, freq: 1, precise_ip: 3, sample_id_all: 1
cpu_core/mem-loads-aux/: type: 4 (cpu_core), size: 136, config: 0x8203 (mem-loads-aux), { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, disabled: 1, freq: 1, precise_ip: 3, sample_id_all: 1
cpu_core/mem-loads,ldlat=30/: type: 4 (cpu_core), size: 136, config: 0x1cd (mem-loads), { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, freq: 1, precise_ip: 2, sample_id_all: 1, { bp_addr, config1 }: 0x1f
cpu_core/mem-stores/P: type: 4 (cpu_core), size: 136, config: 0x2cd (mem-stores), { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|ADDR|CPU|PERIOD|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, disabled: 1, freq: 1, precise_ip: 3, sample_id_all: 1
dummy:u: type: 1 (software), size: 136, config: 0x9 (PERF_COUNT_SW_DUMMY), { sample_period, sample_freq }: 1, sample_type: IP|TID|TIME|ADDR|CPU|IDENTIFIER|DATA_SRC|WEIGHT_STRUCT, read_format: ID|LOST, exclude_kernel: 1, exclude_hv: 1, mmap: 1, comm: 1, task: 1, mmap_data: 1, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1, ksymbol: 1, bpf_event: 1
# Tip: use 'perf evlist -g' to show group information
root@...ber:/tmp#

But there is something strange, 'cpu_core/mem-loads-aux/' doesn't have
/P, i.e. shouldn't try to set precise_ip to 3, but according to 'perf
evlist -v' it is setting it to 3.

I thought maybe it could be related to groups, but:

root@...ber:/tmp# perf evlist -g
cpu_atom/mem-loads,ldlat=30/P
cpu_atom/mem-stores/P
{cpu_core/mem-loads-aux/,cpu_core/mem-loads,ldlat=30/}
cpu_core/mem-stores/P
dummy:u
root@...ber:/tmp# 

But then, in tools/perf/arch/x86/util/mem-events.c

struct perf_mem_event perf_mem_events_intel[PERF_MEM_EVENTS__MAX] = {
        E("ldlat-loads",        "%s/mem-loads,ldlat=%u/P",      "mem-loads",    true,   0),
        E("ldlat-stores",       "%s/mem-stores/P",              "mem-stores",   false,  0),
        E(NULL,                 NULL,                           NULL,           false,  0),
};

struct perf_mem_event perf_mem_events_intel_aux[PERF_MEM_EVENTS__MAX] = {
        E("ldlat-loads",        "{%s/mem-loads-aux/,%s/mem-loads,ldlat=%u/}:P", "mem-loads",    true,   MEM_LOADS_AUX),
        E("ldlat-stores",       "%s/mem-stores/P",              "mem-stores",   false,  0),
        E(NULL,                 NULL,                           NULL,           false,  0),
};

It has the :P for that group, maybe that is going to fallback?

I tried:

Breakpoint 1, evsel__precise_ip_fallback (evsel=0xf4a260) at util/evsel.c:1969
1969	{
(gdb) bt
#0  evsel__precise_ip_fallback (evsel=0xf4a260) at util/evsel.c:1969
#1  0x00000000005dfb09 in evsel__open_cpu (evsel=0xf4a260, cpus=0xf53840, threads=0xf5bfa0, start_cpu_map_idx=0, end_cpu_map_idx=16) at util/evsel.c:2577
#2  0x00000000005dfc54 in evsel__open (evsel=0xf4a260, cpus=0xf53840, threads=0xf5bfa0) at util/evsel.c:2603
#3  0x000000000042cbea in record__open (rec=0xec2ce0 <record>) at builtin-record.c:1370
#4  0x00000000004304a1 in __cmd_record (rec=0xec2ce0 <record>, argc=2, argv=0xf58180) at builtin-record.c:2489
#5  0x0000000000434840 in cmd_record (argc=2, argv=0xf58180) at builtin-record.c:4260
#6  0x0000000000469e93 in __cmd_record (argc=3, argv=0x7fffffffde20, mem=0x7fffffffd260, options=0x7fffffffd080) at builtin-mem.c:170
#7  0x000000000046b2f3 in cmd_mem (argc=4, argv=0x7fffffffde20) at builtin-mem.c:538
#8  0x00000000004c0414 in run_builtin (p=0xec6098 <commands+696>, argc=5, argv=0x7fffffffde20) at perf.c:351
#9  0x00000000004c06bb in handle_internal_command (argc=5, argv=0x7fffffffde20) at perf.c:404
#10 0x00000000004c0814 in run_argv (argcp=0x7fffffffdc0c, argv=0x7fffffffdc00) at perf.c:448
#11 0x00000000004c0b5d in main (argc=5, argv=0x7fffffffde20) at perf.c:560
(gdb) print evsel__name(evsel)
$1 = 0xf529b0 "cpu_core/mem-loads,ldlat=30/"
(gdb) p evsel->core.attr.precise_ip 
$2 = 3
(gdb) p evsel->precise_max
$3 = true
(gdb)

And it fell back to precise_ip=2, the previous attempt at opening with 3
resulted in EINVAL.

It should have that precise level reflected in the evsel name :-\

Ran out of time, hope the above helps.

Apart from that, from a purely regression fix, your patch gets the
previous behaviour, from this isolated test I made, so:

Tested-by: Arnaldo Carvalho de Melo <acme@...hat.com>

- Arnaldo

> Thanks,
> Namhyung
> 
> 
> ---8<---
> diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c
> index f745723d486ba962..d22c5df1701eccc5 100644
> --- a/tools/perf/util/evsel.c
> +++ b/tools/perf/util/evsel.c
> @@ -2571,12 +2571,12 @@ static int evsel__open_cpu(struct evsel *evsel, struct perf_cpu_map *cpus,
>  	if (err == -EMFILE && rlimit__increase_nofile(&set_rlimit))
>  		goto retry_open;
>  
> -	if (err == -EOPNOTSUPP && evsel__precise_ip_fallback(evsel))
> -		goto retry_open;
> -
>  	if (err == -EINVAL && evsel__detect_missing_features(evsel))
>  		goto fallback_missing_features;
>  
> +	if (evsel__precise_ip_fallback(evsel))
> +		goto retry_open;
> +
>  	if (evsel__handle_error_quirks(evsel, err))
>  		goto retry_open;
>  

Powered by blists - more mailing lists