Fix flaky test xray/basic-filtering.cpp

[nickitat]

Increase time thresholds and sleep time to decrease the probability of failure.

Closes: #175866

[llvmbot]

@llvm/pr-subscribers-xray

Author: Nikita Taranov (nickitat)

Changes

Increase time thresholds and sleep time to decrease the probability of failure.

Closes: #175866

---

Full diff: https://github.com/llvm/llvm-project/pull/186611.diff

1 Files Affected:

• (modified) compiler-rt/test/xray/TestCases/Posix/basic-filtering.cpp (+3-3)

diff --git a/compiler-rt/test/xray/TestCases/Posix/basic-filtering.cpp b/compiler-rt/test/xray/TestCases/Posix/basic-filtering.cpp
index 1d03efce976c5..821aba587b0d3 100644
--- a/compiler-rt/test/xray/TestCases/Posix/basic-filtering.cpp
+++ b/compiler-rt/test/xray/TestCases/Posix/basic-filtering.cpp
@@ -5,7 +5,7 @@
 // RUN: rm -f basic-filtering-*
 // RUN: env XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1 \
 // RUN:     xray_logfile_base=basic-filtering- \
-// RUN:     xray_naive_log_func_duration_threshold_us=1000 \
+// RUN:     xray_naive_log_func_duration_threshold_us=100000 \
 // RUN:     xray_naive_log_max_stack_depth=2" %run %t 2>&1 | \
 // RUN:     FileCheck %s
 // RUN: ls basic-filtering-* | head -1 | tr -d '\n' > %t.log
@@ -17,7 +17,7 @@
 // Now check support for the XRAY_BASIC_OPTIONS environment variable.
 // RUN: env XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1 \
 // RUN:     xray_logfile_base=basic-filtering-" \
-// RUN: env XRAY_BASIC_OPTIONS="func_duration_threshold_us=1000 max_stack_depth=2" \
+// RUN: env XRAY_BASIC_OPTIONS="func_duration_threshold_us=100000 max_stack_depth=2" \
 // RUN:     %run %t 2>&1 | FileCheck %s
 // RUN: ls basic-filtering-* | head -1 | tr -d '\n' > %t.log
 // RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
@@ -43,7 +43,7 @@
 [[clang::xray_always_instrument]] void __attribute__((noinline))
 always_shows() {
   struct timespec sleep;
-  sleep.tv_nsec = 2000000;
+  sleep.tv_nsec = 200000000;
   sleep.tv_sec = 0;
   struct timespec rem;
   while (nanosleep(&sleep, &rem) == -1)

[boomanaiden154]

It's unclear why this fixes the issue.

And if you have reproduced this locally and this makes the frequency of failure much lower, this is still only a bandaid fix. We shouldn't be relying on timing in the first place to ensure a test passes.

[nickitat]

In both failures I observed (in the linked issue and my PR), the failure happened because the filtered function was found in the output. As far as I understand the test, it basically expects the printf call to complete within 1ms. This is not reliable.
Here is an example of failure:

cycle-frequency: 1000000000
...
# |        10:  - { type: 0, func-id: 1, function: 'filtered()', cpu: 0, thread: 1727500, process: 1727500, kind: function-enter, tsc: 1768342884408292851, data: '' } 
# | not:61      !~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~  error: no match expected
# |        11:  - { type: 0, func-id: 1, function: 'filtered()', cpu: 0, thread: 1727500, process: 1727500, kind: function-exit, tsc: 1768342884413080044, data: '' } 

i.e., ~4.8ms. The proposed fix raises this limit to 100ms, which, as you rightfully mentioned, is not a guarantee but should still lower flakiness by a significant amount.

I think you'd agree that the test's fundamental unreliability is not a good reason to do nothing about it and continue randomly failing CI checks in unrelated PRs.