From 2e733994c1847aac5098a726da09a056ec8106e8 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Thu, 8 Oct 2026 16:49:26 +0000 Subject: [PATCH] test(scheduler-sim-decision-trace): prove tracing never changes scheduling Task 6.3: the contention and extra replays run with tracing off, all jobs at summary and full level, and a job subset, in step and continue mode; decisions, full pend reasons, --sim-output recordings, snapshots, --sim-verify results and per-step accounting dumps are identical. Co-Authored-By: Claude Opus 5.5 (1M context) --- .../scheduler-sim-decision-trace/tasks.md | 3 +- src/scheduler/testsuite/meson.build | 36 + src/scheduler/testsuite/test_repl_trace_e2e.h | 5 + .../testsuite/test_repl_trace_e2e_fixture.c | 2 +- .../testsuite/test_trace_equivalence.c | 698 ++++++++++++++++++ .../testsuite/test_trace_equivalence.h | 38 + .../testsuite/test_trace_equivalence_cmp.c | 283 +++++++ 7 files changed, 1063 insertions(+), 2 deletions(-) create mode 100644 src/scheduler/testsuite/test_trace_equivalence.c create mode 100644 src/scheduler/testsuite/test_trace_equivalence.h create mode 100644 src/scheduler/testsuite/test_trace_equivalence_cmp.c diff --git a/.kiro/specs/scheduler-sim-decision-trace/tasks.md b/.kiro/specs/scheduler-sim-decision-trace/tasks.md index cc08a4bf..74196958 100644 --- a/.kiro/specs/scheduler-sim-decision-trace/tasks.md +++ b/.kiro/specs/scheduler-sim-decision-trace/tasks.md @@ -329,7 +329,7 @@ - Done when the error-path test passes under ASAN and each injected fault produces its specified trace lines. - _Requirements: 2.4, 3.2, 4.4, 4.5, 5.7_ -- [ ] 6.3 Prove tracing never changes scheduling +- [x] 6.3 Prove tracing never changes scheduling - Run the contention replay four ways: tracing off, all jobs at summary level, all jobs at full level, and a job subset. - Every run must produce identical decision sequences, pend-reason sets, final accounting state, `--sim-verify` results and `--sim-output` recordings (apart from wall-clock fields). - With tracing off, the baseline transcript (as updated in 5.2) must stay unchanged. @@ -375,3 +375,4 @@ - 5.3: sim_loop.c calls the repl.h gates. Session begin runs after a successful begin-session and before reconcile/signal_go; session end runs after the drain and verify tail, before plugin_end_session. The drain loop handles TRACE first (skipping verify, record, echo and breakpoint), then echo gate, `check_trace`, `check_decision`, `rec_free`, free. The reconstructed block uses the new gate `xce_repl_trace_reconstructed` (`repl_trace_on_reconstructed` in repl_trace_emit.c). Settles the 1.7 OPEN item (both free sites). A reviewer's trace-on vs trace-off run of the contention fixture gave byte-identical --sim-output, identical verify and identical decisions. - 6.1: the e2e test (test_repl_trace_e2e.c, its _fixture.c and .h) drives the built xce_scheduler: step/full/all with the file copy, continue/breakpoint/summary/info trace, and selected jobs over a run-time extra fixture with compounds, an array and a selection mismatch. `XCE_TRACE_E2E_DUMP=1` prints the transcript. Findings: a compound dispatch shows one entry per member on a shared host, which is faithful (merge_job_alloc keys on instid); `break DECISION jobid=` matches only raw decimal ids, a pre-existing repl_break.c bug logged separately. - 6.2: test_trace_error_paths.c injects seven faults into the real allocator thread. Hooked sources are #included for the macro renames; the rest are linked so the wraps see their callers. `XCE_TRACE_ERR_DUMP=1` prints the rendered traces. The 2.2 OPEN item is fixed: a limit_row OOM now marks the record incomplete, sets LIMIT via `sched_trace_host_limit_hit(rec, NULL, NULL)` and continues. The 4.2 OPEN item is fixed: an array listing OOM prints "[sim] info trace: array : cannot list its elements: ". The capture and store tests now #include their sources. +- 6.3: test_trace_equivalence.c (with _cmp.c and .h) runs four variants (off, all/summary, all/full+file, subset) in step and continue mode over the contention and 6.1 extra replays. It compares decoded decisions with full pend reasons, recording and snapshot bytes, verify output, and per-step worker/resource/limit dumps; `XCE_TRACE_EQUIV_DUMP=1` prints the transcripts. No difference was found. job->accounts is compared only indirectly, through snapshot job->allocs and the used totals. diff --git a/src/scheduler/testsuite/meson.build b/src/scheduler/testsuite/meson.build index 4c1b2156..f75815ae 100644 --- a/src/scheduler/testsuite/meson.build +++ b/src/scheduler/testsuite/meson.build @@ -2973,3 +2973,39 @@ sched_trace_error_paths_test = executable( test('scheduler trace error paths test', sched_trace_error_paths_test, suite: 'scheduler', env: ['ASAN_OPTIONS=detect_leaks=0']) + +# scheduler-sim-decision-trace task 6.3 (Requirements 10.1-10.5, 11.4; +# design.md "Testing Strategy" -> "Equivalence Tests (Requirement 10)"): +# tracing never changes scheduling. Runs the built xce_scheduler +# (`depends: scheduler`) on the task 1.1 contention replay and the task 6.1 +# extra replay four ways (trace off, all/summary, all/full with a file, a job +# subset), in step and continue mode, with --sim-verify and --sim-output, +# and compares decisions and pend reasons, the recording, the final +# snapshot, the verify result and the REPL's accounting dumps. Links the +# 6.1 fixture file for write_extra_replay() and the real scheduler_srcs for +# the replay writer and decoders. +sched_trace_equivalence_test_srcs = ['test_trace_equivalence.c', + 'test_trace_equivalence_cmp.c', + 'test_repl_trace_e2e_fixture.c'] +foreach f : scheduler_srcs + if f != 'src/main.c' + sched_trace_equivalence_test_srcs += ['../' + f] + endif +endforeach + +sched_trace_equivalence_test = executable( + 'sched_trace_equivalence_test', + sched_trace_equivalence_test_srcs, + include_directories:[incdir], + dependencies: [scheduler_test_deps], + c_args: ['-DXCE_SCHEDULER_BIN="' + scheduler.full_path() + '"', + '-DXCE_BASELINE_DIR="' + + (meson.current_source_dir() / 'fixtures' + / 'repl_trace_baseline') + + '"'], + install: false) + +test('scheduler trace equivalence test', + sched_trace_equivalence_test, suite: 'scheduler', + env: ['ASAN_OPTIONS=detect_leaks=0'], + depends: scheduler) diff --git a/src/scheduler/testsuite/test_repl_trace_e2e.h b/src/scheduler/testsuite/test_repl_trace_e2e.h index 1f6d6547..475fd420 100644 --- a/src/scheduler/testsuite/test_repl_trace_e2e.h +++ b/src/scheduler/testsuite/test_repl_trace_e2e.h @@ -21,6 +21,11 @@ typedef struct { /* Reads a whole file (NULL and *len = 0 when it cannot be read). */ char* slurp(const char* path, long* len); +/* Writes the extra replay (compound requirements, a job array, a + * host-selection mismatch; see the fixture file) to `dest`. Also used by + * test_trace_equivalence.c (task 6.3). */ +void write_extra_replay(const char* dest); + /* Runs the built scheduler on `replay` (BASE_REPLAY or EXTRA_REPLAY) in a * fresh work directory with `script` on stdin; fills r->out with the * console transcript. Asserts a normal exit with status 0. */ diff --git a/src/scheduler/testsuite/test_repl_trace_e2e_fixture.c b/src/scheduler/testsuite/test_repl_trace_e2e_fixture.c index fd3c846d..e585fb2b 100644 --- a/src/scheduler/testsuite/test_repl_trace_e2e_fixture.c +++ b/src/scheduler/testsuite/test_repl_trace_e2e_fixture.c @@ -387,7 +387,7 @@ static uint64_t array_elem(uint32_t k) * cluster-wide limit (6 of 6 in use) * 3000 after 201 and both elements finish: 202 and 203 are tried again */ -static void write_extra_replay(const char* dest) +void write_extra_replay(const char* dest) { char record_dir[PATH_MAX]; char path[PATH_MAX]; diff --git a/src/scheduler/testsuite/test_trace_equivalence.c b/src/scheduler/testsuite/test_trace_equivalence.c new file mode 100644 index 00000000..14eed3fc --- /dev/null +++ b/src/scheduler/testsuite/test_trace_equivalence.c @@ -0,0 +1,698 @@ +/* + * test_trace_equivalence.c - scheduler-sim-decision-trace spec, task 6.3 + * (Requirements 10.1-10.5, 11.4; design.md "Testing Strategy" -> + * "Equivalence Tests (Requirement 10)" item 1, "Invariant Cross-Check" item + * 1; steering scheduler-driver-equivalence.md): tracing never changes + * scheduling. + * + * Each replay is run by the real, built xce_scheduler (XCE_SCHEDULER_BIN) in + * interactive simulation mode with --sim-verify and --sim-output, four ways: + * OFF no trace command at all; + * SUMMARY `trace on all level summary`; + * FULL `trace on all level full file trace.txt` (inline and file); + * SUBSET `trace on job level full`. + * Every traced run must match the OFF run on: + * - the decision sequence and pend-reason sets: every recorded session's + * begin round and decisions (op, time, job, hosts and allocation + * counts), pend reasons compared in full with job_preason_eq() (10.1); + * - the --sim-output recording, byte for byte apart from the header's + * wall-clock recordingStartWall (10.2); + * - the REPL `snapshot` taken at the end, likewise (10.2, 10.3: job state + * and job->allocs, from which job->accounts is rebuilt); + * - the --sim-verify result: the mismatch lines of the log without the + * logger's time/thread prefix (10.2); + * - the final accounting state as the REPL shows it: `info worker all` + * (each worker's resInUse), `info resource all` (sharedInUse), `info + * limit all` (limit accounting), `info jobs`, `info summary` and `info + * job` for every job (10.3). In step mode the same dumps follow every + * step, so the accounting is compared after every session too. + * These dumps are compared as part of the console transcript, reduced to + * the lines tracing is allowed to leave alone (10.4, 10.5): + * - always dropped: each trace block ("[trace] " header plus its indented + * or "..." body lines) and the trace command's own "[sim] trace: " + * replies; + * - continue mode also drops decision echo lines ("[sim] DISPATCH/PEND/ + * PREEMPT jobid=") and round roll-ups ("[sim] round "): Requirement + * 7.3/7.4 prints a traced round's decisions and reports it on its own, + * so those lines legitimately differ. The decisions themselves are still + * compared through the recording and the decoded sessions. + * In step mode nothing else is dropped: the reduced traced transcript + * must equal the OFF transcript byte for byte. + * The trace-off transcript against the pre-feature baseline (10.4) is + * sched_repl_trace_baseline_test's job; this file anchors the OFF verify + * result of the contention replay to that baseline's sim_verify.txt. + * + * Replays: the task 1.1 contention fixture (license, cluster-wide and + * host-scoped limits, a parallel job, an alternative-requirement job whose + * first alternative is rolled back) and the task 6.1 extra replay + * (write_extra_replay(): satisfied and failing compound requirements, a job + * array, a host-selection mismatch). Each runs in step and in continue mode. + * + * Cross-check: the OFF step-mode recording of each replay, which holds real + * recorded decisions, is replayed again under every trace variant with + * --sim-verify, and must verify with no mismatch at all. + * + * test_comparisons_detect_a_perturbation proves the comparisons are not + * vacuous: one changed byte or field in a copy of each compared input is + * reported. The comparisons live in test_trace_equivalence_cmp.c. + */ +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include + +#include "controller.capnp.h" +#include "recording.h" +#include "scheduler.h" + +#include "test_repl_trace_e2e.h" +#include "test_trace_equivalence.h" + +#define INPUT_NAME "input.replay" +#define SCRIPT_NAME "script.txt" +#define OUT_NAME "console.txt" +#define ERR_NAME "stderr.txt" +#define LOG_NAME "sched.log" +#define SIM_OUT_NAME "out.replay" +#define SNAP_NAME "final.replay" +#define VERIFY_FIX "sim_verify.txt" + +#define MISMATCH_TAG "decision verification MISMATCH" +#define VERIFY_MARK "sim_log_mismatch " MISMATCH_TAG + +#define NSTEPS 10 /* more than either replay's sessions */ + +enum { V_OFF, V_SUMMARY, V_FULL, V_SUBSET, NVARIANTS }; +enum { M_STEP, M_CONTINUE }; + +static const char* const g_variant_names[NVARIANTS] = { "off", "summary", + "full", "subset" }; + +typedef struct { + const char* name; + const char* subset; /* SUBSET's job list */ + const char* jobs; /* every job, for the final `info job` dumps */ +} replay_case_t; + +static const replay_case_t g_contention = { + BASE_REPLAY, "0-0-0-105 0-0-0-107", + "0-0-0-101 0-0-0-102 0-0-0-103 0-0-0-104 0-0-0-105 0-0-0-106 " + "0-0-0-107 0-0-0-108" +}; +static const replay_case_t g_extra = { + EXTRA_REPLAY, "0-0-0-202 0-0-0-32768", + "0-0-0-201 0-0-0-202 0-0-0-32768[1] 0-0-0-32768[2] 0-0-0-203" +}; + +typedef struct { + char dir[PATH_MAX]; + char* console; /* full transcript */ + long console_len; + char* view; /* transcript reduced as the header comment says */ + char* verify; /* --sim-verify mismatch lines */ +} eq_run_t; + +void setUp(void) { return; } +void tearDown(void) { return; } + +/* ---------------------------------------------------------------------- */ +/* Files and the child process */ +/* ---------------------------------------------------------------------- */ + +static void join_path(char* out, size_t outsz, const char* dir, + const char* name) +{ + int n = snprintf(out, outsz, "%s/%s", dir, name); + + TEST_ASSERT_TRUE_MESSAGE((n > 0) && ((size_t)n < outsz), + "path too long"); +} + +static void spit(const char* path, const char* buf, long len) +{ + FILE* f = fopen(path, "wb"); + + TEST_ASSERT_NOT_NULL_MESSAGE(f, path); + TEST_ASSERT_EQUAL_INT64(len, (long)fwrite(buf, 1, (size_t)len, f)); + TEST_ASSERT_EQUAL_INT(0, fclose(f)); +} + +static void copy_file(const char* from, const char* to) +{ + long len; + char* buf = slurp(from, &len); + + TEST_ASSERT_NOT_NULL_MESSAGE(buf, from); + spit(to, buf, len); + free(buf); +} + +/* The work directory of the extra replay, generated once. */ +static char g_gen_dir[PATH_MAX]; + +static void input_of(const replay_case_t* rc, char* out, size_t outsz) +{ + if (strcmp(rc->name, BASE_REPLAY) == 0) { + join_path(out, outsz, XCE_BASELINE_DIR, BASE_REPLAY); + return; + } + if (g_gen_dir[0] == '\0') { + char path[PATH_MAX]; + + snprintf(g_gen_dir, sizeof(g_gen_dir), "/tmp/sched_treq_gen_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(g_gen_dir)); + join_path(path, sizeof(path), g_gen_dir, EXTRA_REPLAY); + write_extra_replay(path); + } + join_path(out, outsz, g_gen_dir, EXTRA_REPLAY); +} + +/* Every mismatch line of the log, cut to start at its message (the logger's + * time/thread prefix dropped). An absent log (nothing logged) is "". */ +static char* extract_verify(const char* log_path) +{ + FILE* f = fopen(log_path, "r"); + char* out = (char*)calloc(1, 1); + size_t len = 0; + char line[8192]; + + TEST_ASSERT_NOT_NULL(out); + if (f == NULL) { + return out; + } + while (fgets(line, sizeof(line), f) != NULL) { + char* start = strstr(line, VERIFY_MARK); + size_t n; + + if (start == NULL) { + TEST_ASSERT_NULL_MESSAGE(strstr(line, MISMATCH_TAG), + "mismatch line without " VERIFY_MARK); + continue; + } + n = strlen(start); + out = (char*)realloc(out, len + n + 1); + TEST_ASSERT_NOT_NULL(out); + memcpy(out + len, start, n + 1); + len += n; + } + fclose(f); + return out; +} + +/* ---------------------------------------------------------------------- */ +/* The reduced transcript */ +/* ---------------------------------------------------------------------- */ + +static bool starts(const char* p, const char* prefix) +{ + return strncmp(p, prefix, strlen(prefix)) == 0; +} + +/* True for a line tracing may add or change in `mode` (header comment). */ +static bool dropped_line(const char* p, int mode, bool* in_trace) +{ + if (starts(p, "[trace] ")) { + *in_trace = true; + return true; + } + if (*in_trace && ((p[0] == ' ') || starts(p, "..."))) { + return true; + } + *in_trace = false; + if (starts(p, "[sim] trace: ")) { + return true; + } + return (mode == M_CONTINUE) + && (starts(p, "[sim] DISPATCH jobid=") + || starts(p, "[sim] PEND jobid=") + || starts(p, "[sim] PREEMPT jobid=") + || starts(p, "[sim] round ")); +} + +static char* reduce_transcript(const char* text, int mode) +{ + char* out = (char*)malloc(strlen(text) + 1); + size_t len = 0; + bool in_trace = false; + const char* p = text; + + TEST_ASSERT_NOT_NULL(out); + while (*p != '\0') { + const char* nl = strchr(p, '\n'); + size_t n = (nl != NULL) ? (size_t)(nl - p) + 1 : strlen(p); + + if (!dropped_line(p, mode, &in_trace)) { + memcpy(out + len, p, n); + len += n; + } + p += n; + } + out[len] = '\0'; + return out; +} + +/* ---------------------------------------------------------------------- */ +/* Running one variant */ +/* ---------------------------------------------------------------------- */ + +static char* build_script(const replay_case_t* rc, int variant, int mode) +{ + char* buf = (char*)calloc(1, 16384); + size_t cap = 16384; + size_t len = 0; + char jobs[512]; + char* save = NULL; + const char* tok; + int i; + + TEST_ASSERT_NOT_NULL(buf); +#define APPEND(...) \ + do { \ + int n_ = snprintf(buf + len, cap - len, __VA_ARGS__); \ + TEST_ASSERT_TRUE((n_ >= 0) && ((size_t)n_ < cap - len)); \ + len += (size_t)n_; \ + } while (0) + if (variant == V_SUMMARY) { + APPEND("trace on all level summary\n"); + } else if (variant == V_FULL) { + APPEND("trace on all level full file %s\n", TRACE_FILE); + } else if (variant == V_SUBSET) { + APPEND("trace on job %s level full\n", rc->subset); + } + if (mode == M_STEP) { + for (i = 0; i < NSTEPS; i++) { + APPEND("step\ninfo worker all\ninfo resource all\n" + "info limit all\n"); + } + } else { + APPEND("continue\n"); + } + APPEND("info summary\ninfo jobs\ninfo worker all\ninfo resource all\n" + "info limit all\ninfo queue all\n"); + snprintf(jobs, sizeof(jobs), "%s", rc->jobs); + for (tok = strtok_r(jobs, " ", &save); tok != NULL; + tok = strtok_r(NULL, " ", &save)) { + APPEND("info job %s\n", tok); + } + APPEND("snapshot %s\nquit\n", SNAP_NAME); +#undef APPEND + return buf; +} + +/* Runs the built scheduler on `input` (copied into a fresh work directory + * as input.replay) with --sim-verify and --sim-output. */ +static void run_variant(eq_run_t* r, const char* input, const char* script, + int mode) +{ + char path[PATH_MAX]; + pid_t pid; + int status; + + memset(r, 0, sizeof(*r)); + snprintf(r->dir, sizeof(r->dir), "/tmp/sched_treq_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(r->dir)); + join_path(path, sizeof(path), r->dir, INPUT_NAME); + copy_file(input, path); + join_path(path, sizeof(path), r->dir, SCRIPT_NAME); + spit(path, script, (long)strlen(script)); + + fflush(stdout); + fflush(stderr); + pid = fork(); + TEST_ASSERT_TRUE_MESSAGE(pid >= 0, "fork must succeed"); + if (pid == 0) { + if ((chdir(r->dir) != 0) + || (freopen(SCRIPT_NAME, "r", stdin) == NULL) + || (freopen(OUT_NAME, "w", stdout) == NULL) + || (freopen(ERR_NAME, "w", stderr) == NULL)) { + _exit(120); + } + setenv("TERM", "dumb", 1); + execl(XCE_SCHEDULER_BIN, XCE_SCHEDULER_BIN, "--sim", INPUT_NAME, + "--interactive", "--sim-verify", "--sim-output", SIM_OUT_NAME, + "--logfile", LOG_NAME, (char*)NULL); + _exit(121); + } + TEST_ASSERT_EQUAL_INT(pid, waitpid(pid, &status, 0)); + TEST_ASSERT_TRUE_MESSAGE(WIFEXITED(status), + "the scheduler must exit normally"); + TEST_ASSERT_EQUAL_INT_MESSAGE(0, WEXITSTATUS(status), + "the session must end with quit's exit(0)"); + + join_path(path, sizeof(path), r->dir, OUT_NAME); + r->console = slurp(path, &(r->console_len)); + TEST_ASSERT_NOT_NULL(r->console); + r->view = reduce_transcript(r->console, mode); + join_path(path, sizeof(path), r->dir, LOG_NAME); + r->verify = extract_verify(path); + if (getenv("XCE_TRACE_EQUIV_DUMP") != NULL) { + fprintf(stderr, "==== %s\n%s", r->dir, r->console); + } +} + +static void run_free(eq_run_t* r) +{ + static const char* const names[] = { INPUT_NAME, SCRIPT_NAME, OUT_NAME, + ERR_NAME, LOG_NAME, SIM_OUT_NAME, + SNAP_NAME, TRACE_FILE }; + char path[PATH_MAX]; + size_t i; + + free(r->console); + free(r->view); + free(r->verify); + if ((r->dir[0] == '\0') || (getenv("XCE_TRACE_EQUIV_DUMP") != NULL)) { + return; + } + for (i = 0; i < sizeof(names) / sizeof(names[0]); i++) { + join_path(path, sizeof(path), r->dir, names[i]); + unlink(path); + } + rmdir(r->dir); +} + +/* ---------------------------------------------------------------------- */ +/* The four-way comparison */ +/* ---------------------------------------------------------------------- */ + +static void assert_none(char* why, const char* what, const char* variant) +{ + char msg[1400]; + + if (why == NULL) { + return; + } + snprintf(msg, sizeof(msg), "%s: %s differs from off: %s", variant, what, + why); + free(why); + TEST_FAIL_MESSAGE(msg); +} + +static void out_path(const eq_run_t* r, const char* name, char* out) +{ + join_path(out, PATH_MAX, r->dir, name); +} + +/* Tracing really happened in a traced run, and only for its selection. */ +static void assert_traced_as_asked(const eq_run_t* r, int variant, + const replay_case_t* rc) +{ + char path[PATH_MAX]; + long len = 0; + char* file; + const char* p; + + if (variant == V_OFF) { + TEST_ASSERT_NULL(strstr(r->console, "[trace] job ")); + return; + } + TEST_ASSERT_NOT_NULL_MESSAGE(strstr(r->console, "[trace] job "), + g_variant_names[variant]); + if (variant == V_SUBSET) { + for (p = strstr(r->console, "[trace] job "); p != NULL; + p = strstr(p + 1, "[trace] job ")) { + const char* id = p + strlen("[trace] job "); + char job[64]; + + /* the base id; an array element's "[k]" is cut off */ + snprintf(job, sizeof(job), "%.*s", (int)strcspn(id, " ["), id); + TEST_ASSERT_NOT_NULL_MESSAGE(strstr(rc->subset, job), + "a subset run traced a job " + "outside its selection"); + } + } + out_path(r, TRACE_FILE, path); + file = slurp(path, &len); + if (variant == V_FULL) { + TEST_ASSERT_TRUE_MESSAGE((file != NULL) && (len > 0), + "the full run must write its trace file"); + } + free(file); +} + +static void assert_equivalent(const replay_case_t* rc, int mode) +{ + eq_run_t runs[NVARIANTS]; + sessions_t base; + char a[PATH_MAX]; + char b[PATH_MAX]; + char in[PATH_MAX]; + int v; + + input_of(rc, in, sizeof(in)); + for (v = 0; v < NVARIANTS; v++) { + char* script = build_script(rc, v, mode); + + run_variant(&runs[v], in, script, mode); + free(script); + assert_traced_as_asked(&runs[v], v, rc); + } + + out_path(&runs[V_OFF], SIM_OUT_NAME, a); + sessions_read(a, &base); + TEST_ASSERT_TRUE_MESSAGE(base.n > 0, "the recording must hold sessions"); + TEST_ASSERT_TRUE_MESSAGE(base.ndispatch > 0, "expected dispatches"); + TEST_ASSERT_TRUE_MESSAGE(base.npend_detail > 0, + "expected pends with detailed reasons"); + TEST_ASSERT_TRUE_MESSAGE(strlen(runs[V_OFF].verify) > 0, + "the input's empty sessions must report " + "verify mismatches"); + TEST_ASSERT_NOT_NULL(strstr(runs[V_OFF].view, "[sim] snapshot written")); + + for (v = V_SUMMARY; v < NVARIANTS; v++) { + const char* name = g_variant_names[v]; + sessions_t got; + + assert_none(text_diff(runs[V_OFF].view, runs[v].view), + "reduced transcript", name); + assert_none(text_diff(runs[V_OFF].verify, runs[v].verify), + "--sim-verify result", name); + out_path(&runs[v], SIM_OUT_NAME, b); + sessions_read(b, &got); + assert_none(sessions_diff(&base, &got), "decision sequence", name); + sessions_free(&got); + assert_none(recording_diff(a, b), "--sim-output recording", name); + { + char sa[PATH_MAX]; + char sb[PATH_MAX]; + + out_path(&runs[V_OFF], SNAP_NAME, sa); + out_path(&runs[v], SNAP_NAME, sb); + assert_none(recording_diff(sa, sb), "final snapshot", name); + } + } + sessions_free(&base); + for (v = 0; v < NVARIANTS; v++) { + run_free(&runs[v]); + } +} + +/* ---------------------------------------------------------------------- */ +/* Tests */ +/* ---------------------------------------------------------------------- */ + +static void test_contention_step_mode_equivalent(void) +{ + assert_equivalent(&g_contention, M_STEP); +} + +static void test_contention_continue_mode_equivalent(void) +{ + assert_equivalent(&g_contention, M_CONTINUE); +} + +static void test_extra_step_mode_equivalent(void) +{ + assert_equivalent(&g_extra, M_STEP); +} + +static void test_extra_continue_mode_equivalent(void) +{ + assert_equivalent(&g_extra, M_CONTINUE); +} + +/* The trace-off verify result of the contention replay is the task 1.1 + * baseline's (its recorded sessions are empty, so every live decision is + * reported): the OFF run here is the untraced simulator of the baseline. */ +static void test_off_verify_matches_baseline(void) +{ + eq_run_t r; + char in[PATH_MAX]; + char fix[PATH_MAX]; + char* script = build_script(&g_contention, V_OFF, M_CONTINUE); + char* exp; + long len; + + input_of(&g_contention, in, sizeof(in)); + run_variant(&r, in, script, M_CONTINUE); + free(script); + join_path(fix, sizeof(fix), XCE_BASELINE_DIR, VERIFY_FIX); + exp = slurp(fix, &len); + TEST_ASSERT_NOT_NULL(exp); + assert_none(text_diff(exp, r.verify), "--sim-verify result", "baseline"); + free(exp); + run_free(&r); +} + +/* A recording with real decisions, from an untraced run, verifies with no + * mismatch when replayed under every trace variant. */ +static void assert_recording_verifies_clean(const replay_case_t* rc) +{ + eq_run_t off; + sessions_t rec; + char in[PATH_MAX]; + char recpath[PATH_MAX]; + char* script = build_script(rc, V_OFF, M_STEP); + int v; + + input_of(rc, in, sizeof(in)); + run_variant(&off, in, script, M_STEP); + free(script); + out_path(&off, SIM_OUT_NAME, recpath); + sessions_read(recpath, &rec); + TEST_ASSERT_TRUE_MESSAGE(rec.ndispatch + rec.npend > 0, + "the recording must hold decisions"); + sessions_free(&rec); + + for (v = 0; v < NVARIANTS; v++) { + eq_run_t r; + char msg[256]; + + script = build_script(rc, v, M_CONTINUE); + run_variant(&r, recpath, script, M_CONTINUE); + free(script); + assert_traced_as_asked(&r, v, rc); + snprintf(msg, sizeof(msg), "%s: %s replay must verify clean", + rc->name, g_variant_names[v]); + TEST_ASSERT_EQUAL_STRING_MESSAGE("", r.verify, msg); + run_free(&r); + } + run_free(&off); +} + +static void test_traced_replay_of_untraced_recording_verifies_clean(void) +{ + assert_recording_verifies_clean(&g_contention); + assert_recording_verifies_clean(&g_extra); +} + +/* Mutation check: each comparison reports one changed byte or field. */ +static void test_comparisons_detect_a_perturbation(void) +{ + eq_run_t r; + sessions_t s1; + sessions_t s2; + char in[PATH_MAX]; + char rec[PATH_MAX]; + char copy[PATH_MAX]; + char* script = build_script(&g_contention, V_OFF, M_STEP); + char* text; + char* hit; + char* why; + char* buf; + long len; + int i; + int j; + bool done = false; + + input_of(&g_contention, in, sizeof(in)); + run_variant(&r, in, script, M_STEP); + free(script); + + /* a state line of the reduced transcript */ + text = strdup(r.view); + TEST_ASSERT_NOT_NULL(text); + hit = strstr(text, "used=3.00"); + TEST_ASSERT_NOT_NULL(hit); + hit[5] = '2'; + why = text_diff(r.view, text); + TEST_ASSERT_NOT_NULL_MESSAGE(why, "a changed state line must show"); + free(why); + free(text); + + /* a verify line */ + text = strdup(r.verify); + TEST_ASSERT_NOT_NULL(text); + text[strlen(text) - 2] ^= 1; + why = text_diff(r.verify, text); + TEST_ASSERT_NOT_NULL(why); + free(why); + free(text); + + /* one byte of the recording after the header */ + out_path(&r, SIM_OUT_NAME, rec); + join_path(copy, sizeof(copy), r.dir, "mutated.replay"); + buf = slurp(rec, &len); + TEST_ASSERT_NOT_NULL(buf); + buf[len - 9] ^= 0x01; + spit(copy, buf, len); + free(buf); + why = recording_diff(rec, copy); + TEST_ASSERT_NOT_NULL_MESSAGE(why, "a changed recording byte must show"); + free(why); + why = recording_diff(rec, rec); + TEST_ASSERT_NULL(why); + unlink(copy); + + /* one pend reason in the decoded decisions */ + sessions_read(rec, &s1); + sessions_read(rec, &s2); + TEST_ASSERT_NULL(sessions_diff(&s1, &s2)); + for (i = 0; (i < s2.n) && !done; i++) { + for (j = 0; (j < s2.s[i]->n_decisions) && !done; j++) { + replay_decision_t* d = s2.s[i]->decisions[j]; + + if ((d->body_which == ReplayDecision_body_pend) + && (d->body.pend->reason != NULL) + && (d->body.pend->reason->nres_reasons > 0)) { + d->body.pend->reason->res_based_reasons[0]->reason++; + done = true; + } + } + } + TEST_ASSERT_TRUE_MESSAGE(done, "expected a pend with resource reasons"); + why = sessions_diff(&s1, &s2); + TEST_ASSERT_NOT_NULL_MESSAGE(why, "a changed pend reason must show"); + free(why); + sessions_free(&s1); + sessions_free(&s2); + + /* the reduction keeps state lines and drops trace lines */ + text = reduce_transcript("[sim] a\n[trace] job 1\n x\n...\n" + " keep\n", + M_STEP); + TEST_ASSERT_EQUAL_STRING("[sim] a\n", text); + free(text); + text = reduce_transcript("[trace] job 1\n x\n[sim] b\n keep\n", + M_STEP); + TEST_ASSERT_EQUAL_STRING("[sim] b\n keep\n", text); + free(text); + run_free(&r); +} + +int main(void) +{ + UNITY_BEGIN(); + RUN_TEST(test_comparisons_detect_a_perturbation); + RUN_TEST(test_off_verify_matches_baseline); + RUN_TEST(test_contention_step_mode_equivalent); + RUN_TEST(test_contention_continue_mode_equivalent); + RUN_TEST(test_extra_step_mode_equivalent); + RUN_TEST(test_extra_continue_mode_equivalent); + RUN_TEST(test_traced_replay_of_untraced_recording_verifies_clean); + if ((g_gen_dir[0] != '\0') && (getenv("XCE_TRACE_EQUIV_DUMP") == NULL)) { + char path[PATH_MAX]; + + join_path(path, sizeof(path), g_gen_dir, EXTRA_REPLAY); + unlink(path); + rmdir(g_gen_dir); + } + return UNITY_END(); +} diff --git a/src/scheduler/testsuite/test_trace_equivalence.h b/src/scheduler/testsuite/test_trace_equivalence.h new file mode 100644 index 00000000..4cd7a2fd --- /dev/null +++ b/src/scheduler/testsuite/test_trace_equivalence.h @@ -0,0 +1,38 @@ +/* + * test_trace_equivalence.h - shared between test_trace_equivalence.c (the + * scenarios) and test_trace_equivalence_cmp.c (the comparisons); + * scheduler-sim-decision-trace task 6.3. + */ +#ifndef TEST_TRACE_EQUIVALENCE_H +#define TEST_TRACE_EQUIVALENCE_H + +#include "typemap.h" + +/* The recorded sessions of a .replay file, decoded. */ +typedef struct { + replay_session_t** s; + int n; + int ndispatch; + int npend; + int npend_detail; /* pends with host/resource reasons */ +} sessions_t; + +/* Each comparison returns NULL when equal, else a malloc'd description of + * the first difference (the caller frees it). */ + +/* First differing line of two texts. */ +char* text_diff(const char* a, const char* b); + +/* Byte comparison of two .replay files (recordings or REPL snapshots) + * apart from the header's wall-clock recordingStartWall. */ +char* recording_diff(const char* a_path, const char* b_path); + +/* Decodes every ReplaySession of a .replay file (asserts it is readable). */ +void sessions_read(const char* path, sessions_t* out); +void sessions_free(sessions_t* s); + +/* Session rounds, decision ops, times, jobs, allocation hosts and counts, + * and pend reasons in full (job_preason_eq()). */ +char* sessions_diff(const sessions_t* a, const sessions_t* b); + +#endif diff --git a/src/scheduler/testsuite/test_trace_equivalence_cmp.c b/src/scheduler/testsuite/test_trace_equivalence_cmp.c new file mode 100644 index 00000000..48e38ef5 --- /dev/null +++ b/src/scheduler/testsuite/test_trace_equivalence_cmp.c @@ -0,0 +1,283 @@ +/* + * test_trace_equivalence_cmp.c - the comparisons of the decision-trace + * equivalence test (test_trace_equivalence.c, which documents what is + * compared and why; scheduler-sim-decision-trace task 6.3): texts, + * .replay files apart from the header's wall-clock field, and the decoded + * recorded sessions (decisions, allocations, pend reasons). Each returns + * NULL when equal, else a malloc'd description of the first difference. + * Kept apart from the scenarios for the 800-line file cap. + */ +#include +#include +#include +#include +#include +#include +#include + +#include + +#include "controller.capnp.h" +#include "preason.h" +#include "recording.h" +#include "scheduler.h" + +#include "test_repl_trace_e2e.h" +#include "test_trace_equivalence.h" + +extern int msg_root_has_shape(struct capn* c, capn_ptr* out, + size_t want_words, size_t want_ptrs); + +/* ---------------------------------------------------------------------- */ +/* Comparisons: each returns NULL when equal, else a description */ +/* ---------------------------------------------------------------------- */ + +static char* describe(const char* fmt, ...) + __attribute__((format(printf, 1, 2))); + +static char* describe(const char* fmt, ...) +{ + char* out = (char*)malloc(1024); + va_list ap; + + TEST_ASSERT_NOT_NULL(out); + va_start(ap, fmt); + vsnprintf(out, 1024, fmt, ap); + va_end(ap); + return out; +} + +/* First differing line of two texts. */ +char* text_diff(const char* a, const char* b) +{ + long i = 0; + long line = 1; + long bol = 0; + + while ((a[i] != '\0') && (a[i] == b[i])) { + if (a[i] == '\n') { + line++; + bol = i + 1; + } + i++; + } + if (a[i] == b[i]) { + return NULL; + } + return describe("line %ld:\n off: %.*s\n traced: %.*s", line, + (int)strcspn(a + bol, "\n"), a + bol, + (int)strcspn(b + bol, "\n"), b + bol); +} + +/* A recording (or snapshot) header without recordingStartWall, and the + * offset just past it. */ +static void read_header(const char* path, replay_header_t* hdr, long* end) +{ + FILE* f = fopen(path, "rb"); + struct capn c; + struct ReplayHeader wire; + ReplayHeader_ptr p; + + TEST_ASSERT_NOT_NULL_MESSAGE(f, path); + TEST_ASSERT_EQUAL_INT(0, capn_init_fp(&c, f, 0)); + p.p = capn_getp(capn_root(&c), 0, 1); + read_ReplayHeader(&wire, p); + memset(hdr, 0, sizeof(*hdr)); + decode_ReplayHeader(hdr, &wire); + capn_free(&c); + *end = ftell(f); + fclose(f); +} + +static bool same_str(const char* a, const char* b) +{ + return (a == b) || ((a != NULL) && (b != NULL) && (strcmp(a, b) == 0)); +} + +/* Byte comparison of two .replay files apart from recordingStartWall. */ +char* recording_diff(const char* a_path, const char* b_path) +{ + replay_header_t ha; + replay_header_t hb; + long ea; + long eb; + long la; + long lb; + char* a = slurp(a_path, &la); + char* b = slurp(b_path, &lb); + char* why = NULL; + long i; + + TEST_ASSERT_NOT_NULL_MESSAGE(a, a_path); + TEST_ASSERT_NOT_NULL_MESSAGE(b, b_path); + read_header(a_path, &ha, &ea); + read_header(b_path, &hb, &eb); + if (!same_str(ha.recorder_version, hb.recorder_version) + || (ha.recording_start_ts != hb.recording_start_ts) + || !same_str(ha.sched_policy, hb.sched_policy) + || (ha.cluster != NULL) || (hb.cluster != NULL)) { + why = describe("header fields differ"); + } else if ((la - ea) != (lb - eb)) { + why = describe("length after the header: %ld != %ld", la - ea, + lb - eb); + } else { + for (i = 0; (i < la - ea) && (a[ea + i] == b[eb + i]); i++) { + } + if (i < la - ea) { + why = describe("byte %ld after the header differs", i); + } + } + free_ReplayHeader(&ha); + free_ReplayHeader(&hb); + free(a); + free(b); + return why; +} + +/* ---------------------------------------------------------------------- */ +/* Decoded decisions */ +/* ---------------------------------------------------------------------- */ + +void sessions_read(const char* path, sessions_t* out) +{ + FILE* f = fopen(path, "rb"); + struct capn c; + int msg = 0; + + memset(out, 0, sizeof(*out)); + TEST_ASSERT_NOT_NULL_MESSAGE(f, path); + while (capn_init_fp(&c, f, 0) == 0) { + capn_ptr root; + + if ((msg++ > 0) + && msg_root_has_shape(&c, &root, ReplaySession_word_count, + ReplaySession_pointer_count)) { + ReplaySession_ptr sp; + replay_session_t* s = NULL; + int i; + + sp.p = root; + decode_ReplaySession_ptr(&s, sp); + TEST_ASSERT_NOT_NULL(s); + out->s = (replay_session_t**)realloc( + out->s, sizeof(*out->s) * (size_t)(out->n + 1)); + TEST_ASSERT_NOT_NULL(out->s); + out->s[out->n++] = s; + for (i = 0; i < s->n_decisions; i++) { + replay_decision_t* d = s->decisions[i]; + + if (d->body_which == ReplayDecision_body_dispatch) { + out->ndispatch++; + } else if (d->body_which == ReplayDecision_body_pend) { + xce_job_preason_t* pr = d->body.pend->reason; + + out->npend++; + if ((pr != NULL) + && ((pr->nhost_reasons + pr->nres_reasons) > 0)) { + out->npend_detail++; + } + } + } + } + capn_free(&c); + } + fclose(f); +} + +void sessions_free(sessions_t* s) +{ + int i; + + for (i = 0; i < s->n; i++) { + free_ReplaySession_ptr(&(s->s[i])); + } + free(s->s); + memset(s, 0, sizeof(*s)); +} + +static char* alloc_diff(const xce_job_alloc_t* a, const xce_job_alloc_t* b) +{ + int h; + + if ((a == NULL) || (b == NULL)) { + return (a == b) ? NULL : describe("alloc NULL on one side"); + } + if ((a->jobid != b->jobid) || (a->nhosts != b->nhosts) + || (a->nres_shared != b->nres_shared)) { + return describe("dispatch %llu: nhosts %d/%d, nres_shared %d/%d", + (unsigned long long)a->jobid, a->nhosts, b->nhosts, + a->nres_shared, b->nres_shared); + } + for (h = 0; h < a->nhosts; h++) { + if (!same_str(a->allocs[h]->host, b->allocs[h]->host) + || (a->allocs[h]->nallocs != b->allocs[h]->nallocs)) { + return describe("dispatch %llu: host %d differs", + (unsigned long long)a->jobid, h); + } + } + return NULL; +} + +static char* decision_diff(const replay_decision_t* a, + const replay_decision_t* b) +{ + char* why = NULL; + + if ((a->ts != b->ts) || (a->body_which != b->body_which)) { + return describe("ts %llu/%llu, op %d/%d", (unsigned long long)a->ts, + (unsigned long long)b->ts, a->body_which, + b->body_which); + } + if (a->body_which == ReplayDecision_body_dispatch) { + return alloc_diff(a->body.dispatch->alloc, b->body.dispatch->alloc); + } + if (a->body_which == ReplayDecision_body_pend) { + if (a->body.pend->jobid != b->body.pend->jobid) { + return describe("pend jobid %llu/%llu", + (unsigned long long)a->body.pend->jobid, + (unsigned long long)b->body.pend->jobid); + } + if (!job_preason_eq(a->body.pend->reason, b->body.pend->reason, + &why)) { + char* out = describe("pend %llu reason: %s", + (unsigned long long)a->body.pend->jobid, + (why != NULL) ? why : "?"); + + free(why); + return out; + } + } + return NULL; +} + +char* sessions_diff(const sessions_t* a, const sessions_t* b) +{ + int i; + int j; + + if (a->n != b->n) { + return describe("session count %d != %d", a->n, b->n); + } + for (i = 0; i < a->n; i++) { + if ((a->s[i]->begin_round != b->s[i]->begin_round) + || (a->s[i]->n_decisions != b->s[i]->n_decisions)) { + return describe("session %d: round %llu/%llu, %d/%d decisions", + i, (unsigned long long)a->s[i]->begin_round, + (unsigned long long)b->s[i]->begin_round, + a->s[i]->n_decisions, b->s[i]->n_decisions); + } + for (j = 0; j < a->s[i]->n_decisions; j++) { + char* why = decision_diff(a->s[i]->decisions[j], + b->s[i]->decisions[j]); + + if (why != NULL) { + char* out = describe("session %d decision %d: %s", i, j, why); + + free(why); + return out; + } + } + } + return NULL; +} +