2023-03-14 10:23:52

by Naresh Kamboju

[permalink] [raw]
Subject: selftests: ftrace: event filter function - test event filtering on functions [FAIL]

Results from Linaro’s test farm.

selftests ftrace failed on qemu-x86_64 and qemu-arm64.
Please find the test log below.

Is this expected to fail ? Am I missing anything ?

Reported-by: Linux Kernel Functional Testing <[email protected]>

kselftest: Running tests in ftrace
TAP version 13
1..1
# selftests: ftrace: ftracetest
# === Ftrace unit tests ===
# [1] Basic trace file check [PASS]

...

# [23] event filter function - test event filtering on functions [FAIL]

...
# [58] Kretprobe %return suffix test [PASS]
# [59] Register/unregister many kprobe events
[ 431.662904] trace_kprobe: Could not probe notrace function startup_64
[ 431.669846] trace_kprobe: Could not probe notrace function _stext
[ 431.674104] trace_kprobe: Could not probe notrace function _text
[ 431.675908] trace_kprobe: Could not probe notrace function
secondary_startup_64
[ 431.677876] trace_kprobe: Could not probe notrace function
secondary_startup_64_no_verify
[ 431.679899] trace_kprobe: Could not probe notrace function __pfx_verify_cpu
[ 431.681738] trace_kprobe: Could not probe notrace function verify_cpu
[ 431.683667] trace_kprobe: Could not probe notrace function
__pfx_sev_verify_cbit
[ 431.685594] trace_kprobe: Could not probe notrace function sev_verify_cbit
[ 431.687381] trace_kprobe: Could not probe notrace function start_cpu0
[ 431.689225] trace_kprobe: Could not probe notrace function __pfx___startup_64
[ 431.691223] trace_kprobe: Could not probe notrace function __startup_64
[ 431.693088] trace_kprobe: Could not probe notrace function
__pfx_startup_64_setup_env
[ 431.695021] trace_kprobe: Could not probe notrace function
startup_64_setup_env
[ 431.697012] trace_kprobe: Could not probe notrace function
__pfx___traceiter_initcall_level
[ 431.700780] trace_kprobe: Could not probe notrace function
__pfx___traceiter_initcall_start
...
[ 439.183587] trace_kprobe: Could not probe notrace function
__pfx_hv_check_msr_access
[ 439.186192] trace_kprobe: Could not probe notrace function
__pfx_kvm_hv_flush_tlb
...

# [106] (instance) event filter function - test event filtering on
functions [FAIL]

...
#
# # of passed: 109
# # of failed: 2
# # of unresolved: 3
# # of untested: 0
# # of unsupported: 3
# # of xfailed: 1
# # of undefined(test bug): 0
not ok 1 selftests: ftrace: ftracetest # exit=1

log link,
https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20230314/testrun/15564370/suite/kselftest-ftrace/test/ftrace_ftracetest/log

--
Linaro LKFT
https://lkft.linaro.org


2023-03-14 13:54:05

by Steven Rostedt

[permalink] [raw]
Subject: Re: selftests: ftrace: event filter function - test event filtering on functions [FAIL]

On Tue, 14 Mar 2023 15:52:44 +0530
Naresh Kamboju <[email protected]> wrote:

> Results from Linaro’s test farm.
>
> selftests ftrace failed on qemu-x86_64 and qemu-arm64.
> Please find the test log below.
>
> Is this expected to fail ? Am I missing anything ?

Could you show the contents of the

logs/<date>/*event-filter-function*

file.

-- Steve


2023-03-15 08:33:07

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: selftests: ftrace: event filter function - test event filtering on functions [FAIL]

Hi Naresh,

On Tue, 14 Mar 2023 15:52:44 +0530
Naresh Kamboju <[email protected]> wrote:

> Results from Linaro’s test farm.
>
> selftests ftrace failed on qemu-x86_64 and qemu-arm64.
> Please find the test log below.

Thanks for reporting!
Can you share the kernel config which you used for this build?
And the kernel is "next-20230314", is that correct?

>
> Is this expected to fail ? Am I missing anything ?

No, it should be a bug. I would like to reproduce it.

Thank you,

>
> Reported-by: Linux Kernel Functional Testing <[email protected]>
>
> kselftest: Running tests in ftrace
> TAP version 13
> 1..1
> # selftests: ftrace: ftracetest
> # === Ftrace unit tests ===
> # [1] Basic trace file check [PASS]
>
> ...
>
> # [23] event filter function - test event filtering on functions [FAIL]
>
> ...
> # [58] Kretprobe %return suffix test [PASS]
> # [59] Register/unregister many kprobe events
> [ 431.662904] trace_kprobe: Could not probe notrace function startup_64
> [ 431.669846] trace_kprobe: Could not probe notrace function _stext
> [ 431.674104] trace_kprobe: Could not probe notrace function _text
> [ 431.675908] trace_kprobe: Could not probe notrace function
> secondary_startup_64
> [ 431.677876] trace_kprobe: Could not probe notrace function
> secondary_startup_64_no_verify
> [ 431.679899] trace_kprobe: Could not probe notrace function __pfx_verify_cpu
> [ 431.681738] trace_kprobe: Could not probe notrace function verify_cpu
> [ 431.683667] trace_kprobe: Could not probe notrace function
> __pfx_sev_verify_cbit
> [ 431.685594] trace_kprobe: Could not probe notrace function sev_verify_cbit
> [ 431.687381] trace_kprobe: Could not probe notrace function start_cpu0
> [ 431.689225] trace_kprobe: Could not probe notrace function __pfx___startup_64
> [ 431.691223] trace_kprobe: Could not probe notrace function __startup_64
> [ 431.693088] trace_kprobe: Could not probe notrace function
> __pfx_startup_64_setup_env
> [ 431.695021] trace_kprobe: Could not probe notrace function
> startup_64_setup_env
> [ 431.697012] trace_kprobe: Could not probe notrace function
> __pfx___traceiter_initcall_level
> [ 431.700780] trace_kprobe: Could not probe notrace function
> __pfx___traceiter_initcall_start
> ...
> [ 439.183587] trace_kprobe: Could not probe notrace function
> __pfx_hv_check_msr_access
> [ 439.186192] trace_kprobe: Could not probe notrace function
> __pfx_kvm_hv_flush_tlb
> ...
>
> # [106] (instance) event filter function - test event filtering on
> functions [FAIL]
>
> ...
> #
> # # of passed: 109
> # # of failed: 2
> # # of unresolved: 3
> # # of untested: 0
> # # of unsupported: 3
> # # of xfailed: 1
> # # of undefined(test bug): 0
> not ok 1 selftests: ftrace: ftracetest # exit=1
>
> log link,
> https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20230314/testrun/15564370/suite/kselftest-ftrace/test/ftrace_ftracetest/log
>
> --
> Linaro LKFT
> https://lkft.linaro.org


--
Masami Hiramatsu (Google) <[email protected]>

2023-03-15 09:12:50

by Naresh Kamboju

[permalink] [raw]
Subject: Re: selftests: ftrace: event filter function - test event filtering on functions [FAIL]

Hi Masami San,


On Wed, 15 Mar 2023 at 14:03, Masami Hiramatsu <[email protected]> wrote:
>
> Hi Naresh,
>
> On Tue, 14 Mar 2023 15:52:44 +0530
> Naresh Kamboju <[email protected]> wrote:
>
> > Results from Linaro’s test farm.
> >
> > selftests ftrace failed on qemu-x86_64 and qemu-arm64.
> > Please find the test log below.
>
> Thanks for reporting!
> Can you share the kernel config which you used for this build?
> And the kernel is "next-20230314", is that correct?

I have attached a test log file and Kconfig file.

>
> >
> > Is this expected to fail ? Am I missing anything ?
>
> No, it should be a bug. I would like to reproduce it.

- Naresh


Attachments:
ftrace-config (169.13 kB)
ftrace-log (348.41 kB)
Download all attachments

2023-03-18 15:28:11

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: selftests: ftrace: event filter function - test event filtering on functions [FAIL]

Hi Naresh,

On Wed, 15 Mar 2023 14:41:51 +0530
Naresh Kamboju <[email protected]> wrote:

> Hi Masami San,
>
>
> On Wed, 15 Mar 2023 at 14:03, Masami Hiramatsu <[email protected]> wrote:
> >
> > Hi Naresh,
> >
> > On Tue, 14 Mar 2023 15:52:44 +0530
> > Naresh Kamboju <[email protected]> wrote:
> >
> > > Results from Linaro’s test farm.
> > >
> > > selftests ftrace failed on qemu-x86_64 and qemu-arm64.
> > > Please find the test log below.
> >
> > Thanks for reporting!
> > Can you share the kernel config which you used for this build?
> > And the kernel is "next-20230314", is that correct?
>
> I have attached a test log file and Kconfig file.

Thanks! I could reproduced.

The error log is here.
----
+ . /mnt/ftrace/test.d/filter/event-filter-function.tc
+ echo 'Test event filter function name'
Test event filter function name
+ echo 0
+ echo 0
+ echo
+ echo 'call_site.function == exit_mmap'
+ echo 1
+ echo 1
+ ls
+ echo 0
+ + wcgrep -l
exit_mmap
+ grep kmem_cache_free trace
+ hitcnt=0
+ + wcgrep -l
-v+ exit_mmap
grep kmem_cache_free trace
+ misscnt=0
+ '[' 0 -eq 0 ]
+ exit_fail
+ exit 1

And the test case is here.
-----
echo 'call_site.function == exit_mmap' > events/kmem/kmem_cache_free/filter
echo 1 > events/kmem/kmem_cache_free/enable
echo 1 > tracing_on
ls > /dev/null
echo 0 > events/kmem/kmem_cache_free/enable

hitcnt=`grep kmem_cache_free trace| grep exit_mmap | wc -l`
misscnt=`grep kmem_cache_free trace| grep -v exit_mmap | wc -l`

if [ $hitcnt -eq 0 ]; then
exit_fail
fi
-----

The test case expects the `ls > /dev/null` involves 'kmem_cache_free' trace
event, but it doesn't.

BTW, this code is a bit fragile because the function caller can be changed
frequently. I think it should sample the events and use one of them.
Let me fix that.

Thank you,


>
> >
> > >
> > > Is this expected to fail ? Am I missing anything ?
> >
> > No, it should be a bug. I would like to reproduce it.
>
> - Naresh


--
Masami Hiramatsu (Google) <[email protected]>