Re: [PATCH v3 8/8] perf test: Update sample filtering test

From: Arnaldo Carvalho de Melo
Date: Wed Jul 31 2024 - 10:10:22 EST

Next message: Andrew Jones: "Re: [PATCH v4 02/13] riscv: Do not fail to build on byte/halfword operations with Zawrs"
Previous message: Ian Rogers: "Re: [PATCH v3 2/2] perf jevents: Autogenerate empty-pmu-events.c"
Next in thread: Namhyung Kim: "Re: [PATCH v3 8/8] perf test: Update sample filtering test"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Wed, Jul 03, 2024 at 03:30:35PM -0700, Namhyung Kim wrote:
> Now it can run the BPF filtering test with normal user if the BPF
> objects are pinned by 'sudo perf record --setup-filter pin'. Let's
> update the test case to verify the behavior. It'll skip the test if the
> filter check is failed from a normal user, but it shows a message how to
> set up the filters.
>
> First, run the test as a normal user and it fails.
>
> $ perf test -vv filtering
> 95: perf record sample filtering (by BPF) tests:
> --- start ---
> test child forked, pid 425677
> Checking BPF-filter privilege
> try 'sudo perf record --setup-filter pin' first. <<<--- here
> bpf-filter test [Skipped permission]
> ---- end(-2) ----
> 95: perf record sample filtering (by BPF) tests : Skip
>
> According to the message, run the perf record command to pin the BPF
> objects.
>
> $ sudo perf record --setup-filter pin
>
> And re-run the test as a normal user.
>
> $ perf test -vv filtering
> 95: perf record sample filtering (by BPF) tests:
> --- start ---
> test child forked, pid 424486
> Checking BPF-filter privilege
> Basic bpf-filter test
> Basic bpf-filter test [Success]
> Failing bpf-filter test
> Error: task-clock event does not have PERF_SAMPLE_CPU
> Failing bpf-filter test [Success]
> Group bpf-filter test
> Error: task-clock event does not have PERF_SAMPLE_CPU
> Error: task-clock event does not have PERF_SAMPLE_CODE_PAGE_SIZE
> Group bpf-filter test [Success]
> ---- end(0) ----
> 95: perf record sample filtering (by BPF) tests : Ok

Ok, so I tested one of the examples you provide as a root user:

root@number:~# perf record -o- -e cycles:u --filter 'period < 10' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.024 MB - ]
perf-exec 228020 53029.825757: 1 cpu_core/cycles/u: 7fe361d1cc11 [unknown] ([unknown])
perf-exec 228020 53029.825760: 1 cpu_core/cycles/u: 7fe361d1cc11 [unknown] ([unknown])
perf 228020 53029.826313: 1 cpu_atom/cycles/u: 7fd80d7ba040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228020 53029.826316: 1 cpu_atom/cycles/u: 7fd80d7ba040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228020 53029.838051: 1 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228020 53029.838054: 1 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228020 53029.838055: 9 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228020 53029.844137: 1 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228020 53029.844139: 1 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
root@number:~# perf record -o- -e cycles:u --filter 'period < 100000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.025 MB - ]
perf-exec 228084 53076.760776: 1 cpu_core/cycles/u: 7f7e7691cc11 [unknown] ([unknown])
perf-exec 228084 53076.760779: 1 cpu_core/cycles/u: 7f7e7691cc11 [unknown] ([unknown])
perf-exec 228084 53076.760779: 10 cpu_core/cycles/u: 7f7e7691cc11 [unknown] ([unknown])
perf-exec 228084 53076.760780: 497 cpu_core/cycles/u: 7f7e7691cc11 [unknown] ([unknown])
perf-exec 228084 53076.760781: 27924 cpu_core/cycles/u: 7f7e7691cc11 [unknown] ([unknown])
perf 228084 53076.761318: 1 cpu_atom/cycles/u: 7f317057d040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.761320: 1 cpu_atom/cycles/u: 7f317057d040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.761321: 14 cpu_atom/cycles/u: 7f317057d040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.761322: 518 cpu_atom/cycles/u: 7f317057d040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.761322: 20638 cpu_atom/cycles/u: 7f317057d040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.768070: 1 cpu_core/cycles/u: 7f317056e898 _dl_relocate_object+0x1d8 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.768072: 1 cpu_core/cycles/u: 7f317056e898 _dl_relocate_object+0x1d8 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.768073: 17 cpu_core/cycles/u: 7f317056e898 _dl_relocate_object+0x1d8 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.768073: 836 cpu_core/cycles/u: 7f317056e898 _dl_relocate_object+0x1d8 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.768074: 44346 cpu_core/cycles/u: 7f317056e89b _dl_relocate_object+0x1db (/usr/lib64/ld-linux-x86-64.so.2)
perf 228084 53076.843976: 1 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228084 53076.843978: 1 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228084 53076.843979: 13 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228084 53076.843979: 563 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228084 53076.843980: 26519 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
perf 228084 53077.482090: 1 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228084 53077.482092: 1 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228084 53077.482093: 15 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228084 53077.482093: 746 cpu_core/cycles/u: 53b062 noploop+0x62 (/home/acme/bin/perf)
perf 228084 53077.482094: 38315 cpu_core/cycles/u: 53b05c noploop+0x5c (/home/acme/bin/perf)
root@number:~#

Filtering by period works as advertised, now I have done as root;

root@number:~# perf record --setup-filter pin
root@number:~# ls -la /sys/fs/bpf/perf_filter/
total 0
drwxr-xr-x. 2 root root 0 Jul 31 10:43 .
drwxr-xr-t. 3 root root 0 Jul 31 10:43 ..
-rw-rw-rw-. 1 root root 0 Jul 31 10:43 dropped
-rw-rw-rw-. 1 root root 0 Jul 31 10:43 filters
-rwxrwxrwx. 1 root root 0 Jul 31 10:43 perf_sample_filter
-rw-rw-rw-. 1 root root 0 Jul 31 10:43 pid_hash
-rw-------. 1 root root 0 Jul 31 10:43 sample_f_rodata
root@number:~# ls -la /sys/fs/bpf/perf_filter/perf_sample_filter
-rwxrwxrwx. 1 root root 0 Jul 31 10:43 /sys/fs/bpf/perf_filter/perf_sample_filter
root@number:~#

And as a normal user I try:

acme@number:~$ perf record -o- -e cycles:u perf test -w noploop | perf script -i- | head
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.204 MB - ]
perf 228218 53158.670585: 1 cpu_atom/cycles/u: 7f2fb1b6e040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.670590: 1 cpu_atom/cycles/u: 7f2fb1b6e040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.670592: 7 cpu_atom/cycles/u: 7f2fb1b6e040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.670593: 117 cpu_atom/cycles/u: 7f2fb1b6e040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.670595: 2152 cpu_atom/cycles/u: 7f2fb1b6e040 _start+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.670604: 38977 cpu_atom/cycles/u: ffffffff99201280 [unknown] ([unknown])
perf 228218 53158.670650: 167064 cpu_atom/cycles/u: 7f2fb1b67d7c intel_check_word.constprop.0+0x16c (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.671472: 232830 cpu_atom/cycles/u: 7f2fb1b75d98 strcmp+0x78 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.672710: 191183 cpu_atom/cycles/u: 7f2fb1b59311 _dl_map_object_from_fd+0xea1 (/usr/lib64/ld-linux-x86-64.so.2)
perf 228218 53158.673461: 158125 cpu_atom/cycles/u: 7f2fb1b77148 strcmp+0x1428 (/usr/lib64/ld-linux-x86-64.so.2)
acme@number:~$

Ok, no filtering, bot samples, lets try to use filtering as with root:

acme@number:~$ perf record -o- -e cycles:u --filter 'period < 10000000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.019 MB - ]
acme@number:~$ perf record -o- -e cycles:u --filter 'period < 10000000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.019 MB - ]
acme@number:~$ perf record -o- -e cycles:u --filter 'period < 10000000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.019 MB - ]
acme@number:~$ perf record -o- -e cycles:u --filter 'period < 10000000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.019 MB - ]
acme@number:~$

acme@number:~$ perf record -v -e cycles:u --filter 'period < 10000000' perf test -w noploop
Using CPUID GenuineIntel-6-B7-1
DEBUGINFOD_URLS=
nr_cblocks: 0
affinity: SYS
mmap flush: 1
comp level: 0
Problems creating module maps, continuing anyway...
pid hash: 228434 -> 13
pid hash: 228434 -> 14
mmap size 528384B
Control descriptor is not initialized
Couldn't start the BPF side band thread:
BPF programs starting from now on won't be annotatable
[ perf record: Woken up 1 times to write data ]
failed to write feature CPU_PMU_CAPS
[ perf record: Captured and wrote 0.009 MB perf.data ]
acme@number:~$

I also tried with task-clock:

acme@number:~$ perf record -o- -e task-clock -c 10000 perf test -w noploop | perf script -i- | head
perf 229784 54146.473644: 10000 task-clock:u: 7faf38f1c622 get_common_indices.constprop.0+0xa2 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473654: 10000 task-clock:u: 7faf38f1d323 update_active.constprop.0+0x383 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473664: 10000 task-clock:u: 7faf38f1cd32 intel_check_word.constprop.0+0x122 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473674: 10000 task-clock:u: 7faf38f1cd7c intel_check_word.constprop.0+0x16c (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473684: 10000 task-clock:u: 7faf38f19de5 __tunable_get_val+0x75 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473704: 10000 task-clock:u: 7faf38f190d0 rtld_mutex_dummy+0x0 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473754: 10000 task-clock:u: 7faf38f1a80e _dl_cache_libcmp+0xe (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473864: 10000 task-clock:u: 7faf38f2adb9 strcmp+0x99 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.473954: 10000 task-clock:u: 7faf38f1aa02 search_cache+0x112 (/usr/lib64/ld-linux-x86-64.so.2)
perf 229784 54146.474024: 10000 task-clock:u: 7faf38f0de38 _dl_map_object_from_fd+0x9c8 (/usr/lib64/ld-linux-x86-64.so.2)
acme@number:~$
acme@number:~$ perf record -o- -e task-clock -c 10000 --filter 'ip < 0xffffffff00000000' perf test -w noploop | perf script -i-
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.127 MB - ]
acme@number:~$

Ideas?

I'm keeping it in my local tree so that I run it through the container
build tests meanwhile we try to understand this, what am I missing?

- Arnaldo

⬢[acme@toolbox perf-tools-next]$ uname -a
Linux toolbox 6.9.10-200.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Jul 18 21:39:30 UTC 2024 x86_64 GNU/Linux
⬢[acme@toolbox perf-tools-next]$ perf -vv
perf version 6.11.rc1.g77a71e434cf4
dwarf: [ on ] # HAVE_DWARF_SUPPORT
dwarf_getlocations: [ on ] # HAVE_DWARF_GETLOCATIONS_SUPPORT
syscall_table: [ on ] # HAVE_SYSCALL_TABLE_SUPPORT
libbfd: [ OFF ] # HAVE_LIBBFD_SUPPORT
debuginfod: [ on ] # HAVE_DEBUGINFOD_SUPPORT
libelf: [ on ] # HAVE_LIBELF_SUPPORT
libnuma: [ on ] # HAVE_LIBNUMA_SUPPORT
numa_num_possible_cpus: [ on ] # HAVE_LIBNUMA_SUPPORT
libperl: [ on ] # HAVE_LIBPERL_SUPPORT
libpython: [ on ] # HAVE_LIBPYTHON_SUPPORT
libslang: [ on ] # HAVE_SLANG_SUPPORT
libcrypto: [ on ] # HAVE_LIBCRYPTO_SUPPORT
libunwind: [ on ] # HAVE_LIBUNWIND_SUPPORT
libdw-dwarf-unwind: [ on ] # HAVE_DWARF_SUPPORT
libcapstone: [ on ] # HAVE_LIBCAPSTONE_SUPPORT
zlib: [ on ] # HAVE_ZLIB_SUPPORT
lzma: [ on ] # HAVE_LZMA_SUPPORT
get_cpuid: [ on ] # HAVE_AUXTRACE_SUPPORT
bpf: [ on ] # HAVE_LIBBPF_SUPPORT
aio: [ on ] # HAVE_AIO_SUPPORT
zstd: [ on ] # HAVE_ZSTD_SUPPORT
libpfm4: [ on ] # HAVE_LIBPFM
libtraceevent: [ on ] # HAVE_LIBTRACEEVENT
bpf_skeletons: [ on ] # HAVE_BPF_SKEL
dwarf-unwind-support: [ on ] # HAVE_DWARF_UNWIND_SUPPORT
libopencsd: [ on ] # HAVE_CSTRACE_SUPPORT
⬢[acme@toolbox perf-tools-next]$ git log --oneline -10
2a24133dc55000b3 (HEAD -> perf-tools-next) perf test: Update sample filtering test
d6fed13469889202 perf record: Add --setup-filter option
d8a2ec627150b7a4 perf record: Fix a potential error handling issue
b0313e52f43035b5 perf bpf-filter: Support separate lost counts for each filter
eb29dacbaf215fda perf bpf-filter: Support pin/unpin BPF object
086e7d06af7ce4eb perf bpf-filter: Split per-task filter use case
d3453d1bb80cdbb2 perf bpf-filter: Pass 'target' to perf_bpf_filter__prepare()
736cd1c7a7105e1d perf bpf-filter: Make filters map a single entry hashmap
96ff640908b9808e perf jevents: Don't stop at the first matched pmu when searching a events table
379fe1f78ed5ceaf perf jevents: Use name for special find value (PMU_EVENTS__NOT_FOUND)
⬢[acme@toolbox perf-tools-next]$

> Signed-off-by: Namhyung Kim <namhyung@xxxxxxxxxx>
> ---
> tools/perf/tests/shell/record_bpf_filter.sh | 13 +++++++------
> 1 file changed, 7 insertions(+), 6 deletions(-)
>
> diff --git a/tools/perf/tests/shell/record_bpf_filter.sh b/tools/perf/tests/shell/record_bpf_filter.sh
> index 31c593966e8c..c5882d620db7 100755
> --- a/tools/perf/tests/shell/record_bpf_filter.sh
> +++ b/tools/perf/tests/shell/record_bpf_filter.sh
> @@ -22,15 +22,16 @@ trap trap_cleanup EXIT TERM INT
> test_bpf_filter_priv() {
> echo "Checking BPF-filter privilege"
>
> - if [ "$(id -u)" != 0 ]
> - then
> - echo "bpf-filter test [Skipped permission]"
> - err=2
> - return
> - fi
> if ! perf record -e task-clock --filter 'period > 1' \
> -o /dev/null --quiet true 2>&1
> then
> + if [ "$(id -u)" != 0 ]
> + then
> + echo "try 'sudo perf record --setup-filter pin' first."
> + echo "bpf-filter test [Skipped permission]"
> + err=2
> + return
> + fi
> echo "bpf-filter test [Skipped missing BPF support]"
> err=2
> return
> --
> 2.45.2.803.g4e1b14247a-goog
>

Next message: Andrew Jones: "Re: [PATCH v4 02/13] riscv: Do not fail to build on byte/halfword operations with Zawrs"
Previous message: Ian Rogers: "Re: [PATCH v3 2/2] perf jevents: Autogenerate empty-pmu-events.c"
Next in thread: Namhyung Kim: "Re: [PATCH v3 8/8] perf test: Update sample filtering test"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]