Skip to content

Commit 3d84462

Browse files
committed
Add timeout to test runner
1 parent ebff5c6 commit 3d84462

1 file changed

Lines changed: 183 additions & 22 deletions

File tree

libs/test/src/test.c

Lines changed: 183 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,8 @@
1111

1212
#include "logger/log.h"
1313

14+
#define TEST_TIMEOUT_MS 1000
15+
1416
#ifdef DEBUG_TEST_FUNCTION
1517
#include <string.h>
1618
#define _STRINGIFY(x) #x
@@ -36,6 +38,20 @@ static void print_line(void) {
3638
}
3739

3840
#ifndef DEBUG_TEST_FUNCTION
41+
#include <poll.h>
42+
#include <signal.h>
43+
#include <time.h>
44+
45+
static long elapsed_ms(const struct timespec* start) {
46+
struct timespec now;
47+
if (clock_gettime(CLOCK_MONOTONIC, &now) != 0) {
48+
return 0;
49+
}
50+
long sec = now.tv_sec - start->tv_sec;
51+
long nsec = now.tv_nsec - start->tv_nsec;
52+
return sec * 1000 + nsec / 1000000;
53+
}
54+
3955
#ifdef TEST_NO_CAPTURE
4056
static void
4157
run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
@@ -50,11 +66,38 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
5066
TestResult result = test_entry->func();
5167
_exit((result == TEST_RESULT_PASS) ? EXIT_SUCCESS : EXIT_FAILURE);
5268
} else {
53-
5469
int status;
55-
waitpid(pid, &status, 0);
70+
bool timed_out = false;
71+
struct timespec start;
72+
clock_gettime(CLOCK_MONOTONIC, &start);
73+
74+
while (true) {
75+
pid_t wait_result = waitpid(pid, &status, WNOHANG);
76+
if (wait_result == pid) {
77+
// Child exited
78+
break;
79+
} else if (wait_result == -1) {
80+
perror("waitpid");
81+
exit(EXIT_FAILURE);
82+
}
83+
84+
long elapsed_time = elapsed_ms(&start);
85+
if (elapsed_time >= TEST_TIMEOUT_MS) {
86+
kill(pid, SIGKILL);
87+
waitpid(pid, &status, 0);
88+
timed_out = true;
89+
break;
90+
}
91+
92+
long remaining_time = TEST_TIMEOUT_MS;
93+
long poll_time =
94+
remaining_time < elapsed_time ? remaining_time : elapsed_time;
95+
struct timespec wait_time = {0, poll_time * 1000L * 1000L};
96+
nanosleep(&wait_time, NULL);
97+
}
5698

57-
if (WIFEXITED(status) && WEXITSTATUS(status) == EXIT_SUCCESS) {
99+
if (!timed_out && WIFEXITED(status)
100+
&& WEXITSTATUS(status) == EXIT_SUCCESS) {
58101
LOG_DIAG(
59102
DEBUG,
60103
TEST,
@@ -70,6 +113,16 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
70113
} else {
71114
print_line();
72115

116+
if (timed_out) {
117+
LOG_WARN(
118+
TEST,
119+
"Test `%s` (\x1b[4m%s:%lu\x1b[0m) exceeded test timeout",
120+
test_entry->name,
121+
test_entry->file,
122+
test_entry->line
123+
);
124+
}
125+
73126
LOG_ERROR(
74127
TEST,
75128
"Test `%s` (\x1b[4m%s:%lu\x1b[0m) failed",
@@ -87,6 +140,7 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
87140
#endif // TEST_NO_CAPTURE
88141

89142
#ifndef TEST_NO_CAPTURE
143+
#include <errno.h>
90144
#include <string.h>
91145

92146
static void
@@ -104,7 +158,7 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
104158
}
105159

106160
if (pid == 0) {
107-
close(pipefd[0]); // we only write
161+
close(pipefd[0]); // child only write
108162

109163
// Save stdout for restore
110164
int saved_stdout = dup(STDOUT_FILENO);
@@ -133,35 +187,132 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
133187
close(saved_stdout);
134188
_exit((result == TEST_RESULT_PASS) ? EXIT_SUCCESS : EXIT_FAILURE);
135189
} else {
136-
close(pipefd[1]); // we only read
190+
close(pipefd[1]); // parent only reads
191+
192+
struct timespec start;
193+
clock_gettime(CLOCK_MONOTONIC, &start);
137194

138-
// Save stdout into buffer
195+
// Buffer for accumulated output
139196
char* buffer = NULL;
140197
size_t buffer_size = 0;
141-
int64_t bytes_read;
142198
char read_buf[4096];
143199

144-
while ((bytes_read = read(pipefd[0], read_buf, sizeof(read_buf))) > 0) {
145-
// Grow buffer
146-
char* old_buffer = buffer;
147-
buffer = realloc(buffer, buffer_size + (size_t)bytes_read + 1);
148-
if (!buffer) {
149-
free(old_buffer);
150-
perror("realloc");
151-
exit(EXIT_FAILURE);
200+
struct pollfd poll_fd = {
201+
.fd = pipefd[0],
202+
.events = POLLIN | POLLHUP | POLLERR
203+
};
204+
205+
bool timed_out = false;
206+
int status = 0;
207+
bool child_exited = 0;
208+
209+
while (1) {
210+
long elapsed_time = elapsed_ms(&start);
211+
if (!child_exited && elapsed_time >= TEST_TIMEOUT_MS) {
212+
kill(pid, SIGKILL);
213+
waitpid(pid, &status, 0);
214+
timed_out = true;
215+
child_exited = true;
216+
}
217+
218+
if (!child_exited) {
219+
pid_t r = waitpid(pid, &status, WNOHANG);
220+
if (r == pid) {
221+
child_exited = 1;
222+
} else if (r == -1) {
223+
perror("waitpid");
224+
}
225+
}
226+
227+
long remaining_time = TEST_TIMEOUT_MS;
228+
long poll_time =
229+
remaining_time < elapsed_time ? remaining_time : elapsed_time;
230+
231+
int poll_return = poll(&poll_fd, 1, (int)poll_time);
232+
if (poll_return > 0) {
233+
if (poll_fd.revents & POLLIN) {
234+
ssize_t n = read(pipefd[0], read_buf, sizeof(read_buf));
235+
if (n > 0) {
236+
char* old = buffer;
237+
buffer = realloc(buffer, buffer_size + (size_t)n + 1);
238+
if (!buffer) {
239+
free(old);
240+
perror("realloc");
241+
exit(EXIT_FAILURE);
242+
}
243+
memcpy(buffer + buffer_size, read_buf, (size_t)n);
244+
buffer_size += (size_t)n;
245+
buffer[buffer_size] = '\0';
246+
} else if (n == 0) {
247+
// EOF from child
248+
break;
249+
} else if (n < 0 && errno != EINTR && errno != EAGAIN) {
250+
perror("read");
251+
break;
252+
}
253+
}
254+
255+
if (poll_fd.revents & (POLLHUP | POLLERR)) {
256+
// drain any remaining bytes
257+
ssize_t n;
258+
while ((n = read(pipefd[0], read_buf, sizeof(read_buf))) > 0
259+
) {
260+
char* old = buffer;
261+
buffer = realloc(buffer, buffer_size + (size_t)n + 1);
262+
if (!buffer) {
263+
free(old);
264+
perror("realloc");
265+
exit(EXIT_FAILURE);
266+
}
267+
memcpy(buffer + buffer_size, read_buf, (size_t)n);
268+
buffer_size += (size_t)n;
269+
buffer[buffer_size] = '\0';
270+
}
271+
break;
272+
}
273+
} else if (poll_return < 0) {
274+
if (errno == EINTR) {
275+
continue;
276+
}
277+
278+
perror("poll");
279+
break;
152280
}
153281

154-
// Copy new bytes to buffer
155-
memcpy(buffer + buffer_size, read_buf, (size_t)bytes_read);
156-
buffer_size += (size_t)bytes_read;
157-
buffer[buffer_size] = '\0';
282+
if (child_exited) {
283+
ssize_t n = read(pipefd[0], read_buf, sizeof(read_buf));
284+
if (n > 0) {
285+
char* old = buffer;
286+
buffer = realloc(buffer, buffer_size + (size_t)n + 1);
287+
if (!buffer) {
288+
free(old);
289+
perror("realloc");
290+
exit(EXIT_FAILURE);
291+
}
292+
293+
memcpy(buffer + buffer_size, read_buf, (size_t)n);
294+
buffer_size += (size_t)n;
295+
buffer[buffer_size] = '\0';
296+
continue; // Continue until all data is read
297+
} else if (n == 0 || (n < 0 && errno == EAGAIN)) {
298+
break;
299+
} else if (n < 0 && errno == EINTR) {
300+
continue;
301+
} else if (n < 0) {
302+
perror("read");
303+
break;
304+
}
305+
}
158306
}
307+
159308
close(pipefd[0]);
160309

161-
int status;
162-
waitpid(pid, &status, 0);
310+
if (!child_exited) {
311+
waitpid(pid, &status, 0);
312+
}
163313

164-
if (WIFEXITED(status) && WEXITSTATUS(status) == EXIT_SUCCESS) {
314+
if (!timed_out && WIFEXITED(status)
315+
&& WEXITSTATUS(status) == EXIT_SUCCESS) {
165316
LOG_DIAG(
166317
DEBUG,
167318
TEST,
@@ -182,6 +333,16 @@ run_forked_test(_TestFuncEntry* test_entry, int* passed, int* failed) {
182333
}
183334
}
184335

336+
if (timed_out) {
337+
LOG_WARN(
338+
TEST,
339+
"Test `%s` (\x1b[4m%s:%lu\x1b[0m) exceeded test timeout",
340+
test_entry->name,
341+
test_entry->file,
342+
test_entry->line
343+
);
344+
}
345+
185346
LOG_ERROR(
186347
TEST,
187348
"Test `%s` (\x1b[4m%s:%lu\x1b[0m) failed",

0 commit comments

Comments
 (0)