lei.chen/myxce
1
0
Fork 1
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

fix(harness): pty CLI tests time their waits with a real clock (bug-1902)

Browse source 
clitest_wait_for_exit/clitest_wait_for_text added CLITEST_POLL_SLICE_MS
per loop instead of measuring time. Once xce_test closes its pty after
'quit', poll() returns at once on every call, so the 5 s budget was used
up within milliseconds while the (ASAN, loaded) child was not yet
reapable -- measured: real exit within 6 ms while the counter reached
58800 ms. The waits now use a CLOCK_MONOTONIC deadline, and
clitest_pump_once naps 10 ms when poll wakes with nothing to read.

Under 16 parallel runs: 12/48 runs failed before, 0/96 after.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-10-02 04:24:07 +00:00
parent 6eaccc7476
commit daeb9041ab
Signed by untrusted user: rshen
GPG key ID: 80533536B0EB651C
1 changed files with 28 additions and 6 deletions
Download patch file Download diff file Expand all files Collapse all files

34
src/harness/testsuite/test_test_cli.c
View file

@ -478,6 +478,19 @@ static int clitest_send_signal(clitest_session_t* sess, int signo)
* as "nothing [more] available right now", not an error -- callers loop
* this via clitest_wait_for_text()/clitest_wait_for_exit() until their own
* condition or timeout is met. */
/* bug-1902: the wait loops below measure real (monotonic) time. They used
* to add CLITEST_POLL_SLICE_MS per iteration, but once the child closes
* the pty, poll() returns at once on every call, so a "5000 ms" budget
* ran out within milliseconds while the child (an ASAN build tearing
* down under load) was not yet reapable. */
static long clitest_now_ms(void)
{
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
return (long)ts.tv_sec * 1000 + ts.tv_nsec / 1000000;
}
static void clitest_pump_once(clitest_session_t* sess,
clitest_buf_t* out_stdout,
clitest_buf_t* out_stderr, int timeout_ms)
@ -494,6 +507,8 @@ static void clitest_pump_once(clitest_session_t* sess,
pfds[1].events = POLLIN;
pfds[1].revents = 0;
bool got = false;
n = poll(pfds, 2, timeout_ms);
if (n <= 0) {
return;
@ -503,14 +518,23 @@ static void clitest_pump_once(clitest_session_t* sess,
r = read(sess->master_fd, tmp, sizeof(tmp));
if (r > 0) {
clitest_buf_append(out_stdout, tmp, (size_t)r);
got = true;
}
}
if (pfds[1].revents & (POLLIN | POLLHUP | POLLERR)) {
r = read(sess->err_fd, tmp, sizeof(tmp));
if (r > 0) {
clitest_buf_append(out_stderr, tmp, (size_t)r);
got = true;
}
}
/* bug-1902: a hung-up pty polls ready with nothing to read; don't spin */
if (!got && (timeout_ms > 0)) {
struct timespec nap = { 0, 10 * 1000000L };
nanosleep(&nap, NULL);
}
}
static bool clitest_wait_for_text(clitest_session_t* sess,
@ -519,12 +543,11 @@ static bool clitest_wait_for_text(clitest_session_t* sess,
const char* needle, bool in_stderr,
int overall_timeout_ms)
{
int elapsed = 0;
long deadline = clitest_now_ms() + overall_timeout_ms;
while (elapsed < overall_timeout_ms) {
while (clitest_now_ms() < deadline) {
clitest_pump_once(sess, out_stdout, out_stderr,
CLITEST_POLL_SLICE_MS);
elapsed += CLITEST_POLL_SLICE_MS;
if (strstr(in_stderr ? out_stderr->data : out_stdout->data,
needle) != NULL) {
return true;
@ -551,14 +574,13 @@ static int clitest_wait_for_exit(clitest_session_t* sess,
clitest_buf_t* out_stderr, int timeout_ms,
int* exit_code)
{
int elapsed = 0;
long deadline = clitest_now_ms() + timeout_ms;
pid_t w;
int status;
while (elapsed < timeout_ms) {
while (clitest_now_ms() < deadline) {
clitest_pump_once(sess, out_stdout, out_stderr,
CLITEST_POLL_SLICE_MS);
elapsed += CLITEST_POLL_SLICE_MS;
w = waitpid(sess->pid, &status, WNOHANG);
if (w == sess->pid) {