Skip to content

Commit 7547801

Browse files
committed
test(cli): the scope fixture names its failing step; no timeout decides readiness
cli_install_skip_binary_unchanged_in_host_namespace_quiesces_nothing failed once on 2026-10-09 at ASSERT(ready), with nothing else in the log. cli_scope_fixture_start returned false silently from any of its setup steps, and a 90 s deadline decided the wait for the host child's readiness. The fixture now records and prints the step that failed: the fixture directory, the host directories, the runner's own image fingerprint, the pipes, the fork, the host's start, or the client connect, with the OS error where one applies. The host child prints which of its own steps failed before it answers 'E'. The readiness wait has no deadline any more, because no timeout may decide a test. The child answers 'R' or 'E', or the pipe reaches EOF when it dies. A child that wedges is left to the harness's per-suite ceiling. New test: cli_scope_fixture_names_its_failing_setup_step. Signed-off-by: Martin Vogel <martin.vogel.tech@gmail.com>
1 parent 459af04 commit 7547801

1 file changed

Lines changed: 80 additions & 42 deletions

File tree

‎tests/test_cli.c‎

Lines changed: 80 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -1572,14 +1572,13 @@ TEST(cli_install_recovers_markerless_stale_rendezvous) {
15721572
* install under test and asks the daemon itself afterwards. */
15731573
#define CLI_SCOPE_HOST_DRAINED 3
15741574
#define CLI_SCOPE_TIMEOUT_MS 5000U
1575-
/* Generous, BOUNDED waits so a wedged host child (a fork-time sanitizer
1576-
* allocator stall is the classic cause — see the posix_spawn fix history)
1577-
* fails the test cleanly instead of hanging the whole suite to the CI
1578-
* wall-clock kill. Each comfortably exceeds the child's own 45 s cohort
1579-
* admission deadline plus a multi-second service start/teardown, so none trips
1580-
* for a merely slow-but-healthy runner; they only convert an otherwise
1581-
* unbounded hang into a deterministic pass/fail. */
1582-
#define CLI_SCOPE_READY_TIMEOUT_MS 90000U
1575+
/* The host child's readiness has NO deadline (USER RULE: no timeout decides a
1576+
* test). The child answers 'R' or 'E', or the pipe reaches EOF when it dies,
1577+
* and the fixture names the failing step in every case. A child that wedges
1578+
* before answering is left to the harness's per-suite ceiling. A 90 s bound
1579+
* used to decide this wait, and on a starved machine (2026-10-09, during a
1580+
* kernel index) ASSERT(ready) failed with nothing in the log to say why.
1581+
* Generous, bounded waits remain for reaping and status probes below. */
15831582
#define CLI_SCOPE_HOST_REAP_TIMEOUT_MS 60000U
15841583
#define CLI_SCOPE_HOST_SERVING_TIMEOUT_MS 15000U
15851584
/* Teardown budget for a child the activation ALREADY drained: its service is
@@ -1621,6 +1620,7 @@ typedef struct {
16211620
char *old_home;
16221621
char *old_cache;
16231622
char *old_shell;
1623+
char failed_step[160]; /* the setup step that failed, "" when ready */
16241624
} cli_scope_fixture_t;
16251625

16261626
static _Noreturn void cli_scope_host_child(const cli_scope_fixture_t *fixture, int ready_fd,
@@ -1632,9 +1632,12 @@ static _Noreturn void cli_scope_host_child(const cli_scope_fixture_t *fixture, i
16321632
cbm_version_cohort_lease_t *lease = NULL;
16331633
cbm_daemon_conflict_t conflict;
16341634
cbm_daemon_runtime_service_t *service = NULL;
1635-
bool admitted = endpoint && manager &&
1636-
cbm_version_cohort_acquire(manager, &fixture->identity, cbm_now_ms() + 45000U,
1637-
&lease, &conflict) == CBM_VERSION_COHORT_OK;
1635+
int acquire_status = -1;
1636+
if (endpoint && manager) {
1637+
acquire_status = (int)cbm_version_cohort_acquire(manager, &fixture->identity,
1638+
cbm_now_ms() + 45000U, &lease, &conflict);
1639+
}
1640+
bool admitted = acquire_status == (int)CBM_VERSION_COHORT_OK;
16381641
if (admitted) {
16391642
cbm_daemon_runtime_service_config_t config = {
16401643
.endpoint = endpoint,
@@ -1654,6 +1657,16 @@ static _Noreturn void cli_scope_host_child(const cli_scope_fixture_t *fixture, i
16541657
}
16551658
bool ready_ok =
16561659
service && cbm_daemon_runtime_service_state(service) == CBM_DAEMON_RUNTIME_SERVICE_RUNNING;
1660+
if (!ready_ok) {
1661+
/* The parent sees only 'E'; say here which step it was. */
1662+
const char *step = !endpoint ? "creating the endpoint"
1663+
: !manager ? "creating the cohort manager"
1664+
: !admitted ? "joining the version cohort"
1665+
: !service ? "starting the runtime service"
1666+
: "reaching the running state";
1667+
(void)fprintf(stderr, "cli scope host: setup failed at %s (cohort status %d)\n", step,
1668+
acquire_status);
1669+
}
16571670
char ready = ready_ok ? 'R' : 'E';
16581671
(void)write(ready_fd, &ready, 1);
16591672
close(ready_fd);
@@ -1701,30 +1714,11 @@ static _Noreturn void cli_scope_host_child(const cli_scope_fixture_t *fixture, i
17011714
_exit(!ready_ok ? 1 : drained ? CLI_SCOPE_HOST_DRAINED : 0);
17021715
}
17031716

1704-
/* Bounded read of the host child's one-byte readiness signal. A child that
1705-
* deadlocks before it can write (a fork-time allocator stall under a sanitizer
1706-
* is the classic cause) must never hang the whole suite on an unbounded read:
1707-
* poll to a generous deadline, then let the caller's ASSERT_TRUE(ready) fail
1708-
* cleanly. Returns the byte, or 0 when the child died, closed the pipe, or
1709-
* never answered in time. */
1710-
static char cli_scope_wait_ready(int fd, uint32_t timeout_ms) {
1711-
uint64_t deadline = cbm_now_ms() + timeout_ms;
1717+
/* Read the host child's one-byte readiness signal, with no deadline: the
1718+
* answer is 'R', 'E', or EOF when the child is gone (see
1719+
* CLI_SCOPE_TIMEOUT_MS). Returns the byte, or 0 on EOF or a read error. */
1720+
static char cli_scope_wait_ready(int fd) {
17121721
for (;;) {
1713-
int64_t remaining = (int64_t)deadline - (int64_t)cbm_now_ms();
1714-
if (remaining <= 0) {
1715-
return 0;
1716-
}
1717-
struct pollfd pfd = {.fd = fd, .events = POLLIN, .revents = 0};
1718-
int r = poll(&pfd, 1, (int)remaining);
1719-
if (r < 0) {
1720-
if (errno == EINTR) {
1721-
continue;
1722-
}
1723-
return 0;
1724-
}
1725-
if (r == 0) {
1726-
return 0; /* deadline reached with no signal */
1727-
}
17281722
char ready = 0;
17291723
ssize_t got = read(fd, &ready, 1);
17301724
if (got == 1) {
@@ -1737,6 +1731,20 @@ static char cli_scope_wait_ready(int fd, uint32_t timeout_ms) {
17371731
}
17381732
}
17391733

1734+
/* Records which setup step failed and says so on stderr, so the caller's
1735+
* ASSERT_TRUE(ready) is never a silent failure. Returns false. */
1736+
static bool cli_scope_setup_failed(cli_scope_fixture_t *fixture, const char *tag, const char *step,
1737+
int os_error) {
1738+
snprintf(fixture->failed_step, sizeof(fixture->failed_step), "%s", step);
1739+
if (os_error != 0) {
1740+
(void)fprintf(stderr, "cli scope fixture %s: setup failed at %s: %s\n", tag, step,
1741+
strerror(os_error));
1742+
} else {
1743+
(void)fprintf(stderr, "cli scope fixture %s: setup failed at %s\n", tag, step);
1744+
}
1745+
return false;
1746+
}
1747+
17401748
/* Reap the host child within a bound: the release signal makes a healthy child
17411749
* break within ~50 ms and finish teardown in a few seconds, so a child still
17421750
* alive past the deadline is wedged — SIGKILL it and reap so the suite always
@@ -1769,7 +1777,7 @@ static bool cli_scope_fixture_start(cli_scope_fixture_t *fixture, const char *ta
17691777
fixture->release_fd = -1;
17701778
snprintf(fixture->tmpdir, sizeof(fixture->tmpdir), "/tmp/cli-guard-scope-%s-XXXXXX", tag);
17711779
if (!cbm_mkdtemp(fixture->tmpdir)) {
1772-
return false;
1780+
return cli_scope_setup_failed(fixture, tag, "creating the fixture directory", errno);
17731781
}
17741782
snprintf(fixture->runtime_parent, sizeof(fixture->runtime_parent), "%s/runtime",
17751783
fixture->tmpdir);
@@ -1782,12 +1790,14 @@ static bool cli_scope_fixture_start(cli_scope_fixture_t *fixture, const char *ta
17821790
char canonical_cache[1024];
17831791
if (test_mkdirp(fixture->runtime_parent) != 0 || !cbm_mkdir_p(fixture->host_cache, 0700) ||
17841792
!cbm_canonical_path(fixture->host_cache, canonical_cache, sizeof(canonical_cache))) {
1785-
return false;
1793+
return cli_scope_setup_failed(fixture, tag, "creating the host directories", errno);
17861794
}
17871795
cbm_normalize_path_sep(canonical_cache);
17881796
cbm_sha256_hex(canonical_cache, strlen(canonical_cache), fixture->host_cache_fingerprint);
17891797
if (!cbm_daemon_runtime_process_build_fingerprint((uint64_t)getpid(), fixture->self_build)) {
1790-
return false;
1798+
/* Fails when the runner's file no longer matches its running image,
1799+
* e.g. a rebuild replaced it mid-run. */
1800+
return cli_scope_setup_failed(fixture, tag, "fingerprinting the runner's own image", 0);
17911801
}
17921802
/* The guard claims the supervisor's captured build; the runner stubs that
17931803
* capture while a runtime service must carry the real image hash. Align
@@ -1807,22 +1817,24 @@ static bool cli_scope_fixture_start(cli_scope_fixture_t *fixture, const char *ta
18071817
int ready_pipe[2] = {-1, -1};
18081818
int release_pipe[2] = {-1, -1};
18091819
if (pipe(ready_pipe) != 0) {
1810-
return false;
1820+
return cli_scope_setup_failed(fixture, tag, "creating the readiness pipe", errno);
18111821
}
18121822
if (pipe(release_pipe) != 0) {
1823+
int pipe_error = errno;
18131824
close(ready_pipe[0]);
18141825
close(ready_pipe[1]);
1815-
return false;
1826+
return cli_scope_setup_failed(fixture, tag, "creating the release pipe", pipe_error);
18161827
}
18171828
pid_t child = fork();
1829+
int fork_error = child < 0 ? errno : 0;
18181830
if (child == 0) {
18191831
close(ready_pipe[0]);
18201832
close(release_pipe[1]);
18211833
cli_scope_host_child(fixture, ready_pipe[1], release_pipe[0]);
18221834
}
18231835
close(ready_pipe[1]);
18241836
close(release_pipe[0]);
1825-
char ready = child > 0 ? cli_scope_wait_ready(ready_pipe[0], CLI_SCOPE_READY_TIMEOUT_MS) : 0;
1837+
char ready = child > 0 ? cli_scope_wait_ready(ready_pipe[0]) : 0;
18261838
bool host_ready = ready == 'R';
18271839
close(ready_pipe[0]);
18281840
fixture->host = child;
@@ -1831,16 +1843,29 @@ static bool cli_scope_fixture_start(cli_scope_fixture_t *fixture, const char *ta
18311843
const char *shell = getenv("SHELL");
18321844
fixture->old_shell = shell ? strdup(shell) : NULL;
18331845
cbm_setenv("SHELL", "/bin/zsh", 1);
1846+
if (child < 0) {
1847+
return cli_scope_setup_failed(fixture, tag, "forking the host", fork_error);
1848+
}
18341849
if (!host_ready) {
1835-
return false;
1850+
return cli_scope_setup_failed(fixture, tag,
1851+
ready == 'E'
1852+
? "starting the host (its own line names the step)"
1853+
: "starting the host, which exited before answering",
1854+
0);
18361855
}
18371856
fixture->endpoint = cbm_daemon_bootstrap_endpoint_new(fixture->runtime_parent);
18381857
cbm_daemon_runtime_connect_result_t connect_result = {0};
18391858
fixture->client = fixture->endpoint
18401859
? cbm_daemon_runtime_client_connect(fixture->endpoint, &fixture->identity,
18411860
CLI_SCOPE_TIMEOUT_MS, &connect_result)
18421861
: NULL;
1843-
return fixture->client != NULL;
1862+
if (!fixture->client) {
1863+
return cli_scope_setup_failed(fixture, tag,
1864+
fixture->endpoint ? "connecting the parent's client"
1865+
: "creating the parent's endpoint",
1866+
0);
1867+
}
1868+
return true;
18441869
}
18451870

18461871
static bool cli_scope_host_serving_within(const cli_scope_fixture_t *fixture, uint32_t timeout_ms) {
@@ -2043,6 +2068,18 @@ TEST(cli_install_skip_binary_unchanged_in_host_namespace_quiesces_nothing) {
20432068
PASS();
20442069
}
20452070

2071+
/* 2026-10-09: ASSERT(ready) failed with nothing in the log, so which setup
2072+
* step broke was unknowable. The fixture now names the step it stopped at. A
2073+
* tag naming a missing directory makes its own mkdtemp fail deterministically;
2074+
* nothing is created, so there is nothing to finish. */
2075+
TEST(cli_scope_fixture_names_its_failing_setup_step) {
2076+
cli_scope_fixture_t fixture;
2077+
bool ready = cli_scope_fixture_start(&fixture, "no-such-parent/x");
2078+
ASSERT_FALSE(ready);
2079+
ASSERT_STR_EQ(fixture.failed_step, "creating the fixture directory");
2080+
PASS();
2081+
}
2082+
20462083
/* cli_scope_install with the activation's stdout captured into out. */
20472084
static int cli_scope_install_captured(cli_scope_fixture_t *fixture, const char *home,
20482085
const char *cache, const char *bin_dir, bool skip_binary,
@@ -17902,6 +17939,7 @@ SUITE(cli) {
1790217939
RUN_TEST(cli_install_binary_into_foreign_home_never_drains_host_cohort);
1790317940
RUN_TEST(cli_install_into_host_namespace_still_drains_host_cohort);
1790417941
RUN_TEST(cli_install_skip_binary_unchanged_in_host_namespace_quiesces_nothing);
17942+
RUN_TEST(cli_scope_fixture_names_its_failing_setup_step);
1790517943
RUN_TEST(cli_install_foreign_home_unreadable_cohort_cache_keeps_host_daemon);
1790617944
RUN_TEST(cli_install_foreign_home_busy_cohort_keeps_host_daemon);
1790717945
#endif

0 commit comments

Comments
 (0)