During the parallel testing, I've noticed some ftrace test failures.  It
seems the regex pattern checks 100 msec of nanosleep with the error
range of 10 msec.  But sometimes it's affected by other processes and
resulted in more time in the syscall.

The following output shows that it took more than 120 msec and failed.
Let's update the regex pattern so that it can allow more drifts.

  perf ftrace profile test
  # Total (us)   Avg (us)   Max (us)      Count   Function
    121279.500 121279.500 121279.500          1   __x64_sys_clock_nanosleep
    121278.400 121278.400 121278.400          1   common_nsleep
    121277.800 121277.800 121277.800          1   hrtimer_nanosleep
    121277.100 121277.100 121277.100          1   do_nanosleep
    341760.289  56960.048 121273.400          6   schedule
       176.200     25.171     31.616          7   scheduler_tick
         0.923      0.923      0.923          1   native_smp_send_reschedule
    345522.360  69104.472 345320.600          5   __x64_sys_execve
    345486.585  69097.317 345312.700          5   do_execveat_common.isra.0
    340730.300 340730.300 340730.300          1   bprm_execve
         1.758      0.879      0.883          2   sched_mm_cid_before_execve
         1.112      1.112      1.112          1   sched_mm_cid_after_execve
  ---- end(-1) ----
   81: perf ftrace tests                                               : FAILED!

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/tests/shell/ftrace.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/perf/tests/shell/ftrace.sh b/tools/perf/tests/shell/ftrace.sh
index a6ee740f0d7eca07..11010711efa193b3 100755
--- a/tools/perf/tests/shell/ftrace.sh
+++ b/tools/perf/tests/shell/ftrace.sh
@@ -72,7 +72,7 @@ test_ftrace_profile() {
     grep sleep "${output}"
     grep schedule "${output}"
     grep execve "${output}"
-    time_re="[[:space:]]+10[[:digit:]]{4}\.[[:digit:]]{3}"
+    time_re="[[:space:]]+1[[:digit:]]{5}\.[[:digit:]]{3}"
     # 100283.000 100283.000 100283.000          1   __x64_sys_clock_nanosleep
     # Check for one *clock_nanosleep line with a Count of just 1 that takes a bit more than 0.1 seconds
     # Strip the _x64_sys part to work with other architectures
-- 
2.47.0.163.g1226f6d8fa-goog

On Sat, 02 Nov 2024 16:17:02 -0700, Namhyung Kim wrote:

> During the parallel testing, I've noticed some ftrace test failures.  It
> seems the regex pattern checks 100 msec of nanosleep with the error
> range of 10 msec.  But sometimes it's affected by other processes and
> resulted in more time in the syscall.
> 
> The following output shows that it took more than 120 msec and failed.
> Let's update the regex pattern so that it can allow more drifts.
> 
> [...]

Applied to perf-tools-next, thanks!

Best regards,
Namhyung

On Sat, Nov 2, 2024 at 4:17 PM Namhyung Kim <namhyung@kernel.org> wrote:
>
> During the parallel testing, I've noticed some ftrace test failures.  It
> seems the regex pattern checks 100 msec of nanosleep with the error
> range of 10 msec.  But sometimes it's affected by other processes and
> resulted in more time in the syscall.
>
> The following output shows that it took more than 120 msec and failed.
> Let's update the regex pattern so that it can allow more drifts.
>
>   perf ftrace profile test
>   # Total (us)   Avg (us)   Max (us)      Count   Function
>     121279.500 121279.500 121279.500          1   __x64_sys_clock_nanosleep
>     121278.400 121278.400 121278.400          1   common_nsleep
>     121277.800 121277.800 121277.800          1   hrtimer_nanosleep
>     121277.100 121277.100 121277.100          1   do_nanosleep
>     341760.289  56960.048 121273.400          6   schedule
>        176.200     25.171     31.616          7   scheduler_tick
>          0.923      0.923      0.923          1   native_smp_send_reschedule
>     345522.360  69104.472 345320.600          5   __x64_sys_execve
>     345486.585  69097.317 345312.700          5   do_execveat_common.isra.0
>     340730.300 340730.300 340730.300          1   bprm_execve
>          1.758      0.879      0.883          2   sched_mm_cid_before_execve
>          1.112      1.112      1.112          1   sched_mm_cid_after_execve
>   ---- end(-1) ----
>    81: perf ftrace tests                                               : FAILED!
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>

Reviewed-by: Ian Rogers <irogers@google.com>

Thanks,
Ian

> ---
>  tools/perf/tests/shell/ftrace.sh | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/tools/perf/tests/shell/ftrace.sh b/tools/perf/tests/shell/ftrace.sh
> index a6ee740f0d7eca07..11010711efa193b3 100755
> --- a/tools/perf/tests/shell/ftrace.sh
> +++ b/tools/perf/tests/shell/ftrace.sh
> @@ -72,7 +72,7 @@ test_ftrace_profile() {
>      grep sleep "${output}"
>      grep schedule "${output}"
>      grep execve "${output}"
> -    time_re="[[:space:]]+10[[:digit:]]{4}\.[[:digit:]]{3}"
> +    time_re="[[:space:]]+1[[:digit:]]{5}\.[[:digit:]]{3}"
>      # 100283.000 100283.000 100283.000          1   __x64_sys_clock_nanosleep
>      # Check for one *clock_nanosleep line with a Count of just 1 that takes a bit more than 0.1 seconds
>      # Strip the _x64_sys part to work with other architectures
> --
> 2.47.0.163.g1226f6d8fa-goog
>