fix(scheduler): recorder silently truncated a round's decisions on realloc failure (bug-1843)

sched_record_session_add_decision() (recording_session.c) grows its
per-round decisions array via realloc(), doubling from 8. On a failed
growth it silently dropped the current decision and every one after it
that round, without marking the round incomplete -- finalize() then
wrote the short array as an ordinary, apparently-complete ReplaySession.
--sim-verify's replay comparison had no way to distinguish that from a
genuinely smaller live round, producing spurious "expected: <none>"
mismatches for jobs that were, in reality, correctly decided live and
simply never recorded. Live scheduling itself was unaffected either
way -- only the .replay file's own record of that one round lost its
tail.

This refutes the leading theory from the prior investigation (replay
seeing a job's first appearance "one round early" via coarser event
batching in sim_loop.c) -- confirmed via targeted diagnostic
instrumentation against the original captured .replay file: replay
deterministically reproduces the full candidate set every round;
the recording itself has the one-round gap.

Fix: track truncation on the session ctx; finalize() now refuses to
write an incomplete session and fails loudly through the same
sched_record_abort_on_error() path every other recording failure in
this subsystem already uses.

TDD: added a regression test forcing a real, deterministic realloc()
failure via -Wl,--wrap=realloc (scoped to this one test binary --
no prior malloc/realloc fault-injection harness existed in this
codebase). Verified genuine red -> green: the test fails without the
fix, passes with it. Full 85/85 scheduler suite green.

Note: this prevents future recordings from losing decisions this way;
it cannot retroactively repair an already-captured .replay file.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-09-23 08:37:42 +00:00
parent 88b370ee84
commit 5ee329b1b8
No known key found for this signature in database
GPG key ID: 5BCDAAE0123E9FE2
5 changed files with 224 additions and 18 deletions

View file

@ -299,6 +299,15 @@ sched_record_session_ctx_new(uint64_t begin_round_ts);
* handled loudly (ERROR log) rather than silently dropped or crashing) --
* see driver.c for the shared rationale. XCE_DECISION_NONE/
* XCE_DECISION_NEW_SESSION are likewise skipped (nothing to record).
*
* bug-1843 fix: if growing `ctx`'s internal decisions array fails
* (realloc() returns NULL), this decision -- and every one still to come
* this round -- goes unrecorded; `ctx` is marked internally so
* sched_record_session_finalize() below refuses to write the resulting
* incomplete ReplaySession as though it were a genuine, smaller round (see
* that function's own doc comment). The live scheduling round itself is
* entirely unaffected either way -- only this round's .replay FILE
* representation is dropped.
*/
extern void sched_record_session_add_decision(sched_record_session_ctx_t* ctx,
uint64_t ts,
@ -310,8 +319,10 @@ extern void sched_record_session_add_decision(sched_record_session_ctx_t* ctx,
* computed from `end_ts` and the tallies sched_record_session_add_decision()
* collected) to `sched->record_file`, then frees `ctx` and everything it
* owns. A NULL `ctx` is a no-op (0 is returned; nothing to free). On a
* write failure, recording is disabled the same way
* sched_record_write_events() does. Always frees `ctx` before returning,
* write failure -- including bug-1843's incomplete-`ctx` case, see
* sched_record_session_finalize()'s own doc comment below -- recording is
* disabled the same way sched_record_write_events() does. Always frees
* `ctx` before returning,
* even on failure or when `sched`'s recording state changed out from under
* the caller between sched_record_session_begin() and this call.
*/
@ -330,8 +341,16 @@ extern int sched_record_session_end(xce_scheduler_t* sched,
* so a caller with no xce_scheduler_t* (the simulation driver,
* sim_record.c, Req 5 AC 17) can finalize+write its own accumulated
* session against its own FILE* (sim->record_file) without that gate.
* Returns 0 on success, a negative errno from write_capnp_message() on
* failure -- same contract sched_record_session_end() itself documents.
* Returns 0 on success, a negative errno on failure -- either from
* write_capnp_message(), or -ENOMEM (bug-1843 fix), without writing
* anything, when `ctx` was marked truncated by a decision-batch growth
* failure inside sched_record_session_add_decision() -- writing `ctx`'s
* necessarily-incomplete `decisions` prefix would otherwise produce a
* ReplaySession wire message indistinguishable from a genuine, smaller
* live round, corrupting the recording in a way --sim-verify has no way to
* detect (bug-1843's own "expected: <none>" spurious mismatches). Same
* "always frees ctx" contract either way -- same contract
* sched_record_session_end() itself documents.
* `ctx` must be non-NULL (unlike sched_record_session_end(), this function
* has no NULL-ctx no-op case -- the caller already knows it has a live ctx
* by construction, since it only ever calls this after a successful

View file

@ -1,3 +1,5 @@
#include <errno.h>
#include <stdbool.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
@ -40,6 +42,26 @@ struct sched_record_session_ctx_s {
int cap;
uint32_t n_dispatched;
uint32_t n_pended;
/* bug-1843 fix: set when sched_record_session_add_decision()'s own
* decisions-array growth failed (realloc() returned NULL) partway
* through this round. `n`/`cap` are left exactly as they were at that
* point (this codebase's own convention elsewhere in this function: a
* failed growth drops the CURRENT decision and returns, never touching
* what was already accumulated) -- so `decisions[0..n)` is a real but
* INCOMPLETE prefix of this round's actual decisions, silently missing
* every decision from the failure point through the round's end.
* sched_record_session_finalize() below checks this flag and refuses to
* write a ReplaySession built from a known-incomplete `decisions` array
* -- a live SCHEDULING round is entirely unaffected (the driver's own
* decision-drain loop still delivers every decision to on_decision()
* regardless of this flag; only the .replay FILE representation of this
* one round is dropped), but writing a truncated-looking-complete
* ReplaySession would silently corrupt the recording in a way
* --sim-verify has no way to distinguish from a genuine live decision
* count of `n` for that round (this is exactly what produced bug-1843's
* spurious "expected: <none>" mismatches on replay). */
bool truncated;
};
/*
@ -198,8 +220,17 @@ void sched_record_session_add_decision(sched_record_session_ctx_t* ctx,
ctx->decisions, (size_t)newcap * sizeof(*narr));
if (narr == NULL) {
ERROR("%s out of memory growing decision batch (n=%d)", __func__,
ctx->n);
/* bug-1843 fix: this decision -- and every one still to come
* this round -- is now unrecorded, silently making `decisions`
* an incomplete prefix of what this round actually decided.
* Mark the ctx so sched_record_session_finalize() refuses to
* write it as if it were complete, instead of producing a
* ReplaySession that looks like a genuine, smaller round. */
ERROR("%s out of memory growing decision batch (n=%d) -- this "
"round's ReplaySession will be dropped as incomplete "
"rather than recorded truncated",
__func__, ctx->n);
ctx->truncated = true;
free_record_decision(rd);
return;
}
@ -229,6 +260,16 @@ void sched_record_session_add_decision(sched_record_session_ctx_t* ctx,
* for every existing (normal-mode) caller. Returns 0 on success, a
* negative errno from write_capnp_message() on failure -- same contract
* sched_record_session_end() itself already documents (recording.h).
*
* bug-1843 fix: also returns -ENOMEM, WITHOUT writing anything, when `ctx`
* was marked truncated (sched_record_session_add_decision()'s own decisions-
* array growth failed partway through this round) -- writing `ctx`'s
* necessarily-incomplete `decisions` prefix as a ReplaySession would produce
* a wire message indistinguishable from a genuine, smaller-than-expected
* live round, which is exactly what let bug-1843's replay comparison report
* spurious "expected: <none>" mismatches for the jobs whose decisions never
* made it into the recording. Same caller contract as every other failure
* this function already reports: `ctx` is still freed before returning.
*/
int sched_record_session_finalize(FILE* f, sched_record_session_ctx_t* ctx,
uint64_t end_ts)
@ -241,6 +282,22 @@ int sched_record_session_finalize(FILE* f, sched_record_session_ctx_t* ctx,
int rc;
int i;
if (ctx->truncated) {
ERROR("%s dropping incomplete ReplaySession at begin_round=%llu "
"(n=%d decisions recorded before a decision-batch growth "
"failure) -- not writing a truncated-looking-complete "
"recording",
__func__, (unsigned long long)ctx->begin_round, ctx->n);
for (i = 0; i < ctx->n; i++) {
free_record_decision(ctx->decisions[i]);
}
free(ctx->decisions);
free(ctx);
return -ENOMEM;
}
memset(&summary, 0, sizeof(summary));
summary.duration_ns
= (end_ts >= ctx->begin_round) ? (end_ts - ctx->begin_round) : 0;

View file

@ -520,6 +520,18 @@ sched_record_lifecycle_test = executable(
['test_record_lifecycle.c'],
include_directories:[incdir],
dependencies: [scheduler_test_deps],
# bug-1843 regression: `-Wl,--wrap=realloc` linker symbol interposition
# (same technique/idiom as scheduler_decision_publish_retry_test's own
# xcecli_* wraps above), so
# test_decision_batch_growth_failure_drops_incomplete_session() can force
# a REAL, deterministic realloc() failure inside
# sched_record_session_add_decision()'s own decisions-array growth --
# this codebase has no other malloc/realloc fault-injection harness, and
# bug-1843's root cause was exactly this growth-failure path silently
# dropping decisions instead of aborting the recording. __wrap_realloc()
# passes through to __real_realloc() for every call except the one this
# test arms, so the other 12 tests in this same binary are unaffected.
link_args: ['-Wl,--wrap=realloc'],
install: false)
# Contract test for the scheduler-side OPCode_schedAdmin request handler

View file

@ -381,6 +381,36 @@ static void* stand_in_allocator_thread_fn(void* arg)
return NULL;
}
/* ---------------------------------------------------------------------- */
/* bug-1843 fault injection: -Wl,--wrap=realloc (meson.build, this target */
/* only) redirects every `realloc` reference in this executable -- */
/* including inside the white-box-#included recording_session.c above -- */
/* to __wrap_realloc() below. Disabled (passes straight through to the */
/* real realloc() via __real_realloc(), the symbol `ld --wrap` reserves */
/* for it) unless a test arms it by setting g_realloc_fail_after; the one */
/* test that does always disarms it again immediately after its one target */
/* call, so the other tests in this binary see completely normal */
/* allocator behavior. */
/* ---------------------------------------------------------------------- */
extern void* __real_realloc(void* ptr, size_t size);
static int g_realloc_fail_after = -1; /* -1 == disabled */
static int g_realloc_call_count = 0;
void* __wrap_realloc(void* ptr, size_t size)
{
if (g_realloc_fail_after >= 0) {
int this_call = g_realloc_call_count++;
if (this_call == g_realloc_fail_after) {
return NULL;
}
}
return __real_realloc(ptr, size);
}
/* ---------------------------------------------------------------------- */
/* Fixture helpers */
/* ---------------------------------------------------------------------- */
@ -1282,6 +1312,94 @@ static void test_write_failure_disables_recording_and_driver_keeps_running(void)
" PASS\n");
}
/* ---------------------------------------------------------------------- */
/* Test 8: bug-1843 regression -- a decision-batch growth failure inside */
/* sched_record_session_add_decision() must not silently produce a */
/* truncated-but-looks-complete ReplaySession. */
/* */
/* Root cause (confirmed via a real captured .replay file plus targeted */
/* diagnostic instrumentation, not just code reading): the decisions-array */
/* growth inside sched_record_session_add_decision() (realloc(), doubling */
/* from 8) silently dropped the current decision and returned on a failed */
/* growth, WITHOUT marking the round's accumulator incomplete -- */
/* sched_record_session_finalize() then wrote whatever prefix HAD */
/* accumulated as an apparently complete, genuine ReplaySession. The LIVE */
/* scheduling round was completely unaffected (on_decision() still fires */
/* for every decision regardless of recording) -- only the .replay FILE's */
/* own record of that one round silently lost its tail. --sim-verify's */
/* replay comparison (sim_loop.c, a completely different file -- NOT the */
/* bug, despite that being the leading theory before this fix) then had no */
/* way to distinguish that from a genuinely smaller live round, and */
/* reported the missing decisions as spurious "expected: <none>" MISMATCH */
/* lines for jobs that were, in reality, correctly decided live and simply */
/* never recorded. */
/* */
/* Forces a REAL realloc() failure (via this executable's own */
/* -Wl,--wrap=realloc, meson.build) on the growth triggered by the 9th */
/* decision (8 -> 16) -- the first growth (0 -> 8) is left unarmed so the */
/* ctx's own normal growth path runs first, same shape as the original */
/* capture (many decisions successfully recorded before the one growth */
/* that failed). */
/* ---------------------------------------------------------------------- */
static void
test_decision_batch_growth_failure_drops_incomplete_session(void)
{
char record_dir[PATH_MAX];
xce_scheduler_t sched;
sched_record_session_ctx_t* ctx;
xce_pendreason_t prs[9];
xce_decision_t dec;
int i;
int rc;
make_tmp_dir(record_dir, sizeof(record_dir), "_decgrowfail");
fixture_init(&sched, record_dir);
TEST_ASSERT_EQUAL_INT(0, sched_record_start(&sched, "decgrowfail.replay"));
TEST_ASSERT_TRUE(sched.recording);
TEST_ASSERT_NOT_NULL(sched.record_file);
ctx = sched_record_session_begin(&sched, xce_core_now(&(sched.core)));
TEST_ASSERT_NOT_NULL(ctx);
dec.op = XCE_DECISION_PEND;
/* First 8 decisions: normal, unarmed growth (0 -> 8). */
for (i = 0; i < 8; i++) {
prs[i].jobid = 3000ULL + (uint64_t)i;
prs[i].reasons = NULL;
dec.u.reason = &(prs[i]);
sched_record_session_add_decision(ctx, xce_core_now(&(sched.core)),
&dec);
}
/* 9th decision triggers the 8 -> 16 growth -- arm the wrap to fail
* exactly this ONE realloc() call, then disarm immediately after. */
g_realloc_call_count = 0;
g_realloc_fail_after = 0;
prs[8].jobid = 3008ULL;
prs[8].reasons = NULL;
dec.u.reason = &(prs[8]);
sched_record_session_add_decision(ctx, xce_core_now(&(sched.core)), &dec);
g_realloc_fail_after = -1;
rc = sched_record_session_end(&sched, ctx, xce_core_now(&(sched.core)));
TEST_ASSERT_TRUE(rc < 0);
/* bug-1843 fix's Observable: routed through the SAME
* sched_record_abort_on_error() cleanup the write-failure test above
* asserts -- recording cleanly disabled, nothing left half-written. */
TEST_ASSERT_FALSE(sched.recording);
TEST_ASSERT_NULL(sched.record_file);
TEST_ASSERT_NULL(sched.record_file_path);
printf("test_decision_batch_growth_failure_drops_incomplete_session:"
" PASS\n");
}
int main(void)
{
UNITY_BEGIN();
@ -1301,6 +1419,7 @@ int main(void)
test_periodic_checkpoint_single_batch_crossing_two_boundaries_checkpoints_once);
RUN_TEST(test_periodic_checkpoint_write_failure_disables_recording_cleanly);
RUN_TEST(test_write_failure_disables_recording_and_driver_keeps_running);
RUN_TEST(test_decision_batch_growth_failure_drops_incomplete_session);
return UNITY_END();
}