[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <2bf277fb-a1b8-47f8-9133-e3ca27327eda@huaweicloud.com>
Date: Fri, 11 Jul 2025 10:48:54 +0800
From: Tengda Wu <wutengda@...weicloud.com>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: Masami Hiramatsu <mhiramat@...nel.org>,
Mathieu Desnoyers <mathieu.desnoyers@...icios.com>,
Shuah Khan <shuah@...nel.org>, Yuanhe Shu <xiangzao@...ux.alibaba.com>,
linux-trace-kernel@...r.kernel.org, linux-kernel@...r.kernel.org,
linux-kselftest@...r.kernel.org
Subject: Re: [PATCH -next] selftests/ftrace: Prevent potential failure in
subsystem-enable test case
On 2025/7/11 3:34, Steven Rostedt wrote:
> On Thu, 10 Jul 2025 13:01:34 +0000
> Tengda Wu <wutengda@...weicloud.com> wrote:
>
>
>>
>> Fixes: 1a4ea83a6e67 ("selftests/ftrace: Limit length in subsystem-enable tests")
>> Signed-off-by: Tengda Wu <wutengda@...weicloud.com>
>> ---
>> .../selftests/ftrace/test.d/event/subsystem-enable.tc | 8 ++++----
>> 1 file changed, 4 insertions(+), 4 deletions(-)
>>
>> diff --git a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
>> index b7c8f29c09a9..3a28adc7b727 100644
>> --- a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
>> +++ b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
>> @@ -19,8 +19,8 @@ echo 'sched:*' > set_event
>> yield
>>
>> count=`head -n 100 trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l`
>> -if [ $count -lt 3 ]; then
>> - fail "at least fork, exec and exit events should be recorded"
>> +if [ $count -eq 0 ]; then
>> + fail "none of scheduler events are recorded"
>> fi
>>
>> do_reset
>> @@ -30,8 +30,8 @@ echo 1 > events/sched/enable
>> yield
>>
>> count=`head -n 100 trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l`
>> -if [ $count -lt 3 ]; then
>> - fail "at least fork, exec and exit events should be recorded"
>> +if [ $count -eq 0 ]; then
>> + fail "none of scheduler events are recorded"
>
> So if there's a bug that causes the system enable to only enable a
> single event, this will no longer catch it?
>
> I rather not let the slide.
>
> Can you test this to see if this works for you?
>
> -- Steve
>
> diff --git a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
> index b7c8f29c09a9..46a9e6d92730 100644
> --- a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
> +++ b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
> @@ -14,11 +14,32 @@ fail() { #msg
> exit_fail
> }
>
> +check_unique() {
> + cat trace_pipe | grep -v '^#' | awk '
> + BEGIN { cnt = 0; }
> + {
> + for (i = 0; i < cnt; i++) {
> + if (event[i] == $5) {
> + break;
> + }
> + }
> + if (i == cnt) {
> + event[cnt++] = $5;
> + if (cnt > 2) {
> + exit;
> + }
> + }
> + }
> + END {
> + printf "%d", cnt;
> + }'
> +}
> +
> echo 'sched:*' > set_event
>
> yield
>
> -count=`head -n 100 trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l`
> +count=`check_unique`
> if [ $count -lt 3 ]; then
> fail "at least fork, exec and exit events should be recorded"
> fi
> @@ -29,7 +50,7 @@ echo 1 > events/sched/enable
>
> yield
>
> -count=`head -n 100 trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l`
> +count=`check_unique`
> if [ $count -lt 3 ]; then
> fail "at least fork, exec and exit events should be recorded"
> fi
The patch works well - after ~50 test iterations, we haven't observed any
recurrence of the test case failures.
However, I'm concerned that using 'cat trace_pipe' (like the original
'cat trace' method) could bring back the stopping problem [1] on slower
systems.
Could a slow trace_pipe reader (slower than sched event generation rate)
reintroduce the original race condition?
[1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=1a4ea83a6e67f1415a1f17c1af5e9c814c882bb5
Some test details:
$ ./ftracetest -vvv subsystem-enable.tc
[...]
+ echo sched:*
+ yield
+ ping 127.0.0.1 -c 1
PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.538 ms
--- 127.0.0.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 1ms
rtt min/avg/max/mdev = 0.538/0.538/0.538/0.000 ms
+ check_unique
+ cat trace_pipe
+ grep -v ^#
+ awk
BEGIN { cnt = 0; }
{
for (i = 0; i < cnt; i++) {
if (event[i] == $5) {
break;
}
}
if (i == cnt) {
event[cnt++] = $5;
if (cnt > 2) {
exit;
}
}
}
END {
printf "%d", cnt;
}
+ count=3
+ [ 3 -lt 3 ]
+ do_reset
[...]
Regards,
Tengda
Powered by blists - more mailing lists