From 4df29606f6d5a9e5ea17a804a068c62dbaba0093 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Thu, 8 Oct 2026 14:42:27 +0000 Subject: [PATCH] feat(scheduler-sim-decision-trace): emit traces inline and apply settings at session boundaries Task 4.6: session begin makes the next settings current, stamps the session number and publishes them to the core; session end withdraws and releases them. Emission marks the round traced, flushes the collapsed range and reprints the suppressed echo in continue mode, renders to the console and the trace file with identical bytes, and stores the record. sim_print_decision is exported unchanged. Co-Authored-By: Claude Opus 5.5 (1M context) --- .../scheduler-sim-decision-trace/tasks.md | 5 +- src/scheduler/include/sim.h | 9 + src/scheduler/meson.build | 1 + src/scheduler/src/repl_internal.h | 33 + src/scheduler/src/repl_trace.c | 2 +- src/scheduler/src/repl_trace_emit.c | 155 ++++ src/scheduler/src/sim_loop.c | 6 +- src/scheduler/testsuite/meson.build | 26 + .../testsuite/test_repl_trace_emit.c | 708 ++++++++++++++++++ 9 files changed, 941 insertions(+), 4 deletions(-) create mode 100644 src/scheduler/src/repl_trace_emit.c create mode 100644 src/scheduler/testsuite/test_repl_trace_emit.c diff --git a/.kiro/specs/scheduler-sim-decision-trace/tasks.md b/.kiro/specs/scheduler-sim-decision-trace/tasks.md index 9a4fd502..0462a1d2 100644 --- a/.kiro/specs/scheduler-sim-decision-trace/tasks.md +++ b/.kiro/specs/scheduler-sim-decision-trace/tasks.md @@ -179,7 +179,7 @@ - _Requirements: 4.1, 4.3, 4.4, 4.5, 4.6, 4.7, 4.8, 4.9, 5.1, 5.2, 5.6, 5.7, 5.8_ - _Depends: 2.2, 3.3_ -- [ ] 4. Simulator REPL trace surface +- [x] 4. Simulator REPL trace surface - [x] 4.1 Render trace records to text, test first (P) - **Hierarchy:** header, selection, requirements, cluster-wide checks and plans, positions and hosts, then the outcome. Every budgeted entry renders as exactly one line, in the order shown in the design's example. - **Summary level:** renders position summaries with per-limit names. @@ -246,7 +246,7 @@ - _Requirements: 8.2, 8.3, 8.4, 8.5, 8.6, 8.7_ - _Depends: 4.3, 4.4_ -- [ ] 4.6 Emit traces inline and apply settings at session boundaries, test first +- [x] 4.6 Emit traces inline and apply settings at session boundaries, test first - At session begin: - reset the per-round traced and flushed flags; - make the next settings current, stamping the session number and resetting the position; @@ -369,3 +369,4 @@ - 4.3: `trace` is parsed from the raw line by repl_trace.c. The settings are a refcounted REPL-side wrapper around xce_sched_trace_ctl_t (trace.h untouched), held as `next`/`cur` in xce_repl_trace_state_t together with session_in_progress, round_traced and round_flushed. The 1.3 bare-id item is settled: an array-aligned bare id adds both an exact and a whole-array selector, so later elements match; status shows that as `[*]`. A range expands to one exact selector per element. The wrapper frees `ctl.policy_name` on its last release, so 4.6 must heap-allocate it. Nothing frees next/cur at REPL shutdown yet, so 4.5/4.6 must add the shutdown path; routing `trace` from repl.c is 5.2. - 4.4: the driver holds its own copy of the scheduler log path in `sim->log_path` (from `sched_sim_args_t.log_path`, else `SCHED_DEFAULT_LOG_PATH` in sim.h, "/tmp/xce_scheduler.log"). The log is always open in sim mode, so 4.5 can `stat(sim->log_path)` for its dev/ino same-file check. - 4.5: the trace FILE* and its dev/ino belong to the refcounted settings, and the last unref flushes and closes it. New functions in repl_internal.h: `repl_trace_settings_file()`, `repl_trace_file_conflicts(sim, path)` (5.2 wires it into `set output`) and `repl_trace_shutdown(sim)` (5.2 calls it on quit/EOF). Shutdown clears core.trace_ctl, releases cur/next, then calls store_fini, which memsets the trace state, so keep that order. 4.6 must emit only through `cur`'s file while it still holds `cur`, and flush after every record, because two append streams may share one file. +- 4.6: the session hooks and emitter are in repl_trace_emit.c: `repl_trace_session_begin/end(sim)` and `repl_trace_on_decision/on_trace_only(sim, d)`, declared in repl_internal.h. `sim_print_decision` is now exported from sim.h. Session begin stamps `session_no = rs->session_count`, which sim_loop.c increments in `xce_repl_check_begin_round` before `xce_core_begin_session`. 5.3 must call session_begin after a successful begin-session and before signal_go/reconciliation, and session_end after the decision stream ends. Emission moves the record to the store (d->trace=NULL); write errors are reported once per session. policy_name is not stamped; capture falls back to the core picker. repl_trace_emit.c is not yet in sched_sim_isolation_lib or its scan (5.1). diff --git a/src/scheduler/include/sim.h b/src/scheduler/include/sim.h index 432ffb8d..1a75dd07 100644 --- a/src/scheduler/include/sim.h +++ b/src/scheduler/include/sim.h @@ -317,4 +317,13 @@ extern void sched_sim_driver_fini(xce_sched_sim_driver_t* sim); extern int sim_prescan_next_nonempty_session(xce_sched_sim_driver_t* sim, uint64_t* out_sessions_ahead); +/* + * sim_print_decision (sim_loop.c) - the per-decision echo line, + * "[sim] DISPATCH|PEND|PREEMPT jobid=", to stdout. Exported so the + * REPL's continue-mode trace emission (repl_trace_emit.c, task 4.6 of the + * scheduler-sim-decision-trace spec, Req 7.3) prints exactly the echo line + * the print gate suppressed. Other ops print nothing. + */ +extern void sim_print_decision(const xce_decision_t* d); + #endif diff --git a/src/scheduler/meson.build b/src/scheduler/meson.build index 9fcb9af5..9921b6d2 100644 --- a/src/scheduler/meson.build +++ b/src/scheduler/meson.build @@ -33,6 +33,7 @@ scheduler_srcs = [ 'src/repl_trace_render_outcome.c', 'src/repl_trace_store.c', 'src/repl_trace.c', + 'src/repl_trace_emit.c', 'src/schedobj.c', 'src/plugin.c', 'src/resource.c', diff --git a/src/scheduler/src/repl_internal.h b/src/scheduler/src/repl_internal.h index 3292c573..78a22570 100644 --- a/src/scheduler/src/repl_internal.h +++ b/src/scheduler/src/repl_internal.h @@ -189,6 +189,7 @@ typedef struct { bool session_in_progress; bool round_traced; bool round_flushed; + bool write_error_reported; /* this session */ htab_t by_job; /* jobid -> repl_trace_entry_s* */ htab_t discarded; /* jobid -> eviction seq */ bool tables_ready; @@ -672,4 +673,36 @@ extern bool repl_trace_file_conflicts(const xce_sched_sim_driver_t* sim, const char* path); extern void repl_trace_shutdown(xce_sched_sim_driver_t* sim); +/* + * Session hooks and inline emission (repl_trace_emit.c, task 4.6, + * design.md "SimIntegration", "ReplTraceControl"; Requirements 1.6, 7.1-7.3, + * 8.1, 8.5). All run on the sim thread; the sim driver calls them through + * the interactive-only gates in repl.h (task 5.2/5.3). + * + * repl_trace_session_begin - after a successful core begin-session, before + * reconciliation. Resets the per-round flags (round_traced, round_flushed, + * write_error_reported) in every mode, sets `cur = ref(next)`, stamps + * cur's ctl with rs->session_count and position 0, and publishes it as + * sim->core.trace_ctl (NULL when tracing is off). + * + * repl_trace_session_end - after the decision stream ends. Withdraws + * sim->core.trace_ctl, drops `cur` (closing its file when `next` no longer + * holds it, 8.5) and clears session_in_progress. + * + * repl_trace_on_decision / repl_trace_on_trace_only - a traced decision + * (after the echo gate) or a trace-only decision. Sets round_traced; in + * continue mode the round's first traced item flushes the collapsed range + * and a traced decision prints its suppressed echo line + * (sim_print_decision); then renders d->trace to stdout and cur's file + * with identical bytes, flushes both, and hands the record to the store, + * leaving d->trace NULL. A write error on the file is reported once per + * session. No-op when d->trace is NULL. + */ +extern void repl_trace_session_begin(xce_sched_sim_driver_t* sim); +extern void repl_trace_session_end(xce_sched_sim_driver_t* sim); +extern void repl_trace_on_decision(xce_sched_sim_driver_t* sim, + xce_decision_t* d); +extern void repl_trace_on_trace_only(xce_sched_sim_driver_t* sim, + xce_decision_t* d); + #endif diff --git a/src/scheduler/src/repl_trace.c b/src/scheduler/src/repl_trace.c index a24bf36e..fed19e57 100644 --- a/src/scheduler/src/repl_trace.c +++ b/src/scheduler/src/repl_trace.c @@ -25,7 +25,7 @@ * started with). Commands build a complete new object and only then * replace `next`, so an invalid argument leaves everything unchanged * (1.9), and a session in progress keeps its own settings (1.6). The - * session hooks that move `next` into `cur` are task 4.6. + * session hooks that move `next` into `cur` are in repl_trace_emit.c. * * Trace file (task 4.5, 8.2-8.7): a named file is opened for appending * when the command runs, after a stat() check that it is not the diff --git a/src/scheduler/src/repl_trace_emit.c b/src/scheduler/src/repl_trace_emit.c new file mode 100644 index 00000000..ba5f000e --- /dev/null +++ b/src/scheduler/src/repl_trace_emit.c @@ -0,0 +1,155 @@ +/* + * repl_trace_emit.c - the trace session hooks and inline trace emission + * (scheduler-sim-decision-trace spec, task 4.6; design.md "SimIntegration", + * "ReplTraceControl", "System Flows" -> "Session lifecycle and capture" and + * "Drain-loop emission order", "Error Handling"; Requirements 1.6, 7.1, + * 7.2, 7.3, 8.1, 8.5). + * + * Session begin makes the `next` settings current for the session and + * publishes their control block to the scheduling core; session end + * withdraws it and drops `cur`, which closes a file that a command replaced + * during the session (the settings object owns the file, repl_trace.c). + * Commands issued during the session change only `next` (1.6). + * + * Emission runs on the sim thread from the drain loop. Order per traced + * item (7.1-7.3): in continue mode the round's first traced item flushes + * the active collapsed range, then a traced decision reprints the echo + * line the print gate suppressed; then the trace goes to stdout and to + * cur's file with identical bytes (one render call, two sinks), both are + * flushed (two append streams may share one file), and the record moves + * to the store. `round_traced` is set in every mode, so a round traced in + * step mode and finished with `continue` is never collapsed (7.4, 5.2). + * + * Writes nothing through tlog (8.7). + */ +#include +#include +#include + +#include "repl_internal.h" +#include "sched/trace.h" +#include "sim.h" + +void repl_trace_session_begin(xce_sched_sim_driver_t* sim) +{ + xce_repl_trace_state_t* ts; + xce_sched_trace_ctl_t* ctl; + + if ((sim == NULL) || (sim->repl_state == NULL)) { + return; + } + ts = &(sim->repl_state->trace); + + /* every mode: a round that ended in step mode leaks nothing (7.3, 7.4) */ + ts->round_traced = false; + ts->round_flushed = false; + ts->write_error_reported = false; + + /* a missed session end must not leak the previous reference */ + repl_trace_settings_unref(ts->cur); + ts->cur = repl_trace_settings_ref(ts->next); + ctl = repl_trace_settings_ctl(ts->cur); + if (ctl != NULL) { + ctl->session_no = sim->repl_state->session_count; + ctl->position = 0; + } + sim->core.trace_ctl = ctl; /* NULL when tracing is off (1.6) */ + ts->session_in_progress = true; +} + +void repl_trace_session_end(xce_sched_sim_driver_t* sim) +{ + xce_repl_trace_state_t* ts; + + if ((sim == NULL) || (sim->repl_state == NULL)) { + return; + } + ts = &(sim->repl_state->trace); + sim->core.trace_ctl = NULL; + /* closes cur's file when `next` no longer holds the settings (8.5) */ + repl_trace_settings_unref(ts->cur); + ts->cur = NULL; + ts->session_in_progress = false; +} + +/* Error Handling: a failed write to the trace file is reported once per + * session; the file stays attached and console output continues. */ +static void check_file(xce_repl_trace_state_t* ts, FILE* file, + int render_err) +{ + int err = 0; + + /* a record larger than the stdio buffer fails inside the renderer's + * writes, so keep that errno rather than whatever fflush leaves */ + if (ferror(file)) { + err = (render_err != 0) ? render_err : EIO; + } + errno = 0; + if ((fflush(file) != 0) && (err == 0)) { + err = (errno != 0) ? errno : EIO; + } + if ((err == 0) && !ferror(file)) { + return; + } + if (err == 0) { + err = EIO; + } + clearerr(file); + if (!ts->write_error_reported) { + const char* path = repl_trace_settings_path(ts->cur); + + fprintf(stdout, "[sim] trace: write to %s failed: %s\n", + (path != NULL) ? path : "(trace file)", strerror(err)); + fflush(stdout); + ts->write_error_reported = true; + } +} + +/* Shared by both entry points; `echo` is false for trace-only decisions. */ +static void emit(xce_sched_sim_driver_t* sim, xce_decision_t* d, bool echo) +{ + xce_repl_trace_state_t* ts; + xce_sched_trace_rec_t* rec; + FILE* file; + int render_err; + + if ((sim == NULL) || (sim->repl_state == NULL) || (d == NULL) + || (d->trace == NULL)) { + return; + } + ts = &(sim->repl_state->trace); + rec = d->trace; + + ts->round_traced = true; /* every mode (7.4) */ + if (sim->repl_state->mode == XCE_REPL_MODE_CONTINUE) { + if (!ts->round_flushed) { + repl_round_collapse_flush(sim); /* 7.3 */ + ts->round_flushed = true; + } + if (echo) { + sim_print_decision(d); /* the line the print gate suppressed */ + } + } + + file = repl_trace_settings_file(ts->cur); + errno = 0; + repl_trace_render(rec, repl_current_units_mode(sim), stdout, file); + render_err = errno; + fflush(stdout); + if (file != NULL) { + check_file(ts, file, render_err); + } + + d->trace = NULL; + repl_trace_store_put(ts, rec); /* takes ownership (7.10) */ +} + +void repl_trace_on_decision(xce_sched_sim_driver_t* sim, xce_decision_t* d) +{ + emit(sim, d, true); +} + +void repl_trace_on_trace_only(xce_sched_sim_driver_t* sim, xce_decision_t* d) +{ + emit(sim, d, false); +} diff --git a/src/scheduler/src/sim_loop.c b/src/scheduler/src/sim_loop.c index 0bd512ef..7a604e45 100644 --- a/src/scheduler/src/sim_loop.c +++ b/src/scheduler/src/sim_loop.c @@ -525,8 +525,12 @@ extern void sim_bootstrap_parjob_allocator(xce_sched_sim_driver_t* sim); * fprintf(stdout, ...) is not `printf` at the symbol level, so the linker * wrap never intercepts it -- matching the established convention every * other REPL/sim print call site in this codebase already follows. + * + * Non-static and declared in sim.h (scheduler-sim-decision-trace task 4.6, + * Req 7.3): continue-mode trace emission (repl_trace_emit.c) reprints the + * echo line the gate below suppressed. The format is unchanged. */ -static void sim_print_decision(const xce_decision_t* d) +void sim_print_decision(const xce_decision_t* d) { char jobidStr[64]; diff --git a/src/scheduler/testsuite/meson.build b/src/scheduler/testsuite/meson.build index bee2f89b..b68e7f22 100644 --- a/src/scheduler/testsuite/meson.build +++ b/src/scheduler/testsuite/meson.build @@ -2797,3 +2797,29 @@ sched_repl_trace_file_test = executable( test('scheduler repl trace file test', sched_repl_trace_file_test, suite: 'scheduler') + +# scheduler-sim-decision-trace task 4.6: the trace session hooks and inline +# trace emission (design.md "SimIntegration", "ReplTraceControl", +# "Drain-loop emission order"; Requirements 1.6, 7.1-7.3, 8.1, 8.5). +# Session begin/end publish and withdraw the settings; step-mode placement; +# continue-mode flush, then echo, then trace; the per-round flags reset at +# session begin; the file copy byte-equal to the console. Links every +# scheduler source except main.c, so the emitter calls the real collapsed- +# range flush (repl_rollup.c) and echo printer (sim_loop.c). Leak detection +# stays on. +sched_repl_trace_emit_test_srcs = ['test_repl_trace_emit.c'] +foreach f : scheduler_srcs + if f != 'src/main.c' + sched_repl_trace_emit_test_srcs += ['../' + f] + endif +endforeach + +sched_repl_trace_emit_test = executable( + 'sched_repl_trace_emit_test', + sched_repl_trace_emit_test_srcs, + include_directories:[incdir], + dependencies: [scheduler_deps, unity_dep], + install: false) + +test('scheduler repl trace emit test', + sched_repl_trace_emit_test, suite: 'scheduler') diff --git a/src/scheduler/testsuite/test_repl_trace_emit.c b/src/scheduler/testsuite/test_repl_trace_emit.c new file mode 100644 index 00000000..970d54a2 --- /dev/null +++ b/src/scheduler/testsuite/test_repl_trace_emit.c @@ -0,0 +1,708 @@ +/* + * test_repl_trace_emit.c - inline trace emission and the trace session + * hooks (scheduler-sim-decision-trace spec, task 4.6; design.md + * "SimIntegration", "ReplTraceControl", "System Flows" -> "Session + * lifecycle and capture" and "Drain-loop emission order", "Error + * Handling"; Requirements 1.6, 7.1, 7.2, 7.3, 8.1, 8.5). + * + * Links every scheduler source except main.c, so the emitter runs against + * the real REPL and simulation code it calls: repl_round_collapse_flush() + * (repl_rollup.c) and the decision echo printer sim_print_decision() + * (sim_loop.c). The sim driver and REPL state are zeroed fixtures; nothing + * is started. Each test drives the hooks the way the drain loop will + * (task 5.3): session begin, then per decision the echo gate (step mode + * prints the echo itself, continue mode suppresses it) followed by the + * emitter, then session end. + * + * Covers: + * - session begin makes `next` current, stamps the session number, + * resets the position and publishes the control block; with tracing + * off it publishes nothing (1.6); + * - session end withdraws the control block, drops `cur` (closing a + * replaced file) and clears the in-progress flag (8.5); + * - step mode: a traced decision's trace follows its echo line, and a + * no-decision trace sits where the echo would be (7.1, 7.2); + * - continue mode: the round's first traced item flushes the collapsed + * range, then the suppressed echo line, then the trace; later items + * do not flush again (7.3); + * - the per-round flags reset at session begin, including after a round + * that ended in step mode; + * - the file copy is byte-equal to the console trace (8.1); + * - a failed write to the trace file is reported once per session. + */ +#define _GNU_SOURCE +#include +#include +#include +#include +#include +#include + +#include + +#include "repl_internal.h" +#include "sched/trace.h" +#include "sim.h" +#include "utils.h" + +#define JOB_A ((uint64_t)42 << 32) +#define JOB_B ((uint64_t)43 << 32) + +static xce_sched_sim_driver_t g_sim; +static xce_sched_repl_state_t g_rs; +static char g_dir[64]; +static char g_cwd[4096]; + +/* stdout capture */ +static int g_cap_fd = -1; +static int g_cap_saved = -1; +static char g_cap_path[64]; + +void setUp(void) +{ + memset(&g_sim, 0, sizeof(g_sim)); + memset(&g_rs, 0, sizeof(g_rs)); + g_rs.units_mode = XCE_REPL_UNITS_BOTH; + g_rs.mode = XCE_REPL_MODE_STEP; + g_sim.interactive = true; + g_sim.repl_state = &g_rs; + + TEST_ASSERT_NOT_NULL(getcwd(g_cwd, sizeof(g_cwd))); + snprintf(g_dir, sizeof(g_dir), "/tmp/xce_trace_emit_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(g_dir)); + TEST_ASSERT_EQUAL_INT(0, chdir(g_dir)); +} + +void tearDown(void) +{ + repl_trace_shutdown(&g_sim); + free(g_rs.collapse_pend_jobids); + g_rs.collapse_pend_jobids = NULL; + g_sim.repl_state = NULL; + unlink("a.trace"); + unlink("b.trace"); + TEST_ASSERT_EQUAL_INT(0, chdir(g_cwd)); + rmdir(g_dir); +} + +/* ---- helpers ------------------------------------------------------------- */ + +static void cap_begin(void) +{ + snprintf(g_cap_path, sizeof(g_cap_path), "/tmp/xce_trace_emit_out_XXXXXX"); + g_cap_fd = mkstemp(g_cap_path); + TEST_ASSERT_TRUE(g_cap_fd >= 0); + fflush(stdout); + g_cap_saved = dup(STDOUT_FILENO); + TEST_ASSERT_TRUE(g_cap_saved >= 0); + TEST_ASSERT_TRUE(dup2(g_cap_fd, STDOUT_FILENO) >= 0); +} + +/* Ends the capture and returns what was printed (caller frees). */ +static char* cap_end(void) +{ + off_t len; + char* buf; + + fflush(stdout); + dup2(g_cap_saved, STDOUT_FILENO); + close(g_cap_saved); + + len = lseek(g_cap_fd, 0, SEEK_CUR); + TEST_ASSERT_TRUE(len >= 0); + buf = (char*)calloc(1, (size_t)len + 1); + TEST_ASSERT_NOT_NULL(buf); + TEST_ASSERT_TRUE(lseek(g_cap_fd, 0, SEEK_SET) == 0); + if (len > 0) { + TEST_ASSERT_TRUE(read(g_cap_fd, buf, (size_t)len) == len); + } + close(g_cap_fd); + unlink(g_cap_path); + return buf; +} + +static void cmd(const char* line) +{ + cap_begin(); + (void)repl_trace_cmd(&g_sim, line); + free(cap_end()); +} + +static char* read_file(const char* path) +{ + FILE* f = fopen(path, "r"); + char* buf; + long len; + + TEST_ASSERT_NOT_NULL(f); + TEST_ASSERT_EQUAL_INT(0, fseek(f, 0, SEEK_END)); + len = ftell(f); + TEST_ASSERT_TRUE(len >= 0); + rewind(f); + buf = (char*)calloc(1, (size_t)len + 1); + TEST_ASSERT_NOT_NULL(buf); + if (len > 0) { + TEST_ASSERT_EQUAL_size_t((size_t)len, fread(buf, 1, (size_t)len, f)); + } + fclose(f); + return buf; +} + +/* A record for `jobid` under the session's published settings. */ +static xce_sched_trace_rec_t* new_rec(uint64_t jobid, + xce_sched_trace_rec_kind_t kind) +{ + xce_sched_trace_ctl_t ctl; + xce_sched_trace_rec_t* rec; + + memset(&ctl, 0, sizeof(ctl)); + ctl.all = true; + ctl.level = XCE_TRACE_LEVEL_SUMMARY; + ctl.line_bound = 1000; + ctl.session_no = 3; + ctl.position = 1; + rec = sched_trace_rec_new(&ctl, jobid, XCE_TRACE_REC_DECISION); + TEST_ASSERT_NOT_NULL(rec); + if (kind != XCE_TRACE_REC_DECISION) { + sched_trace_rec_finish(rec, kind, 0); + } + return rec; +} + +/* The renderer's text for `rec` in the current units mode (caller frees). */ +static char* render(const xce_sched_trace_rec_t* rec) +{ + char* buf = NULL; + size_t len = 0; + FILE* f = open_memstream(&buf, &len); + + TEST_ASSERT_NOT_NULL(f); + repl_trace_render(rec, g_rs.units_mode, f, NULL); + fclose(f); + TEST_ASSERT_TRUE(len > 0); + return buf; +} + +typedef struct { + xce_decision_t d; + xce_job_alloc_t alloc; + xce_pendreason_t reason; +} fixture_decision_t; + +static void dispatch_of(fixture_decision_t* f, uint64_t jobid) +{ + memset(f, 0, sizeof(*f)); + f->alloc.jobid = jobid; + f->d.op = XCE_DECISION_DISPATCH; + f->d.u.alloc = &(f->alloc); + f->d.trace = new_rec(jobid, XCE_TRACE_REC_DECISION); +} + +static void pend_of(fixture_decision_t* f, uint64_t jobid) +{ + memset(f, 0, sizeof(*f)); + f->reason.jobid = jobid; + f->d.op = XCE_DECISION_PEND; + f->d.u.reason = &(f->reason); + f->d.trace = new_rec(jobid, XCE_TRACE_REC_DECISION); +} + +static void trace_only_of(fixture_decision_t* f, uint64_t jobid) +{ + memset(f, 0, sizeof(*f)); + f->d.op = XCE_DECISION_TRACE; + f->d.trace = new_rec(jobid, XCE_TRACE_REC_NOT_FOUND); +} + +static char* echo_line(const char* op, uint64_t jobid) +{ + char id[64]; + char* s = NULL; + + TEST_ASSERT_TRUE(fmt_jobid(id, sizeof(id), jobid) >= 0); + TEST_ASSERT_TRUE(asprintf(&s, "[sim] %s jobid=%s\n", op, id) > 0); + return s; +} + +/* What the drain loop does per traced decision (task 5.3): the echo gate + * (prints only in step mode), then the emitter. */ +static void drain_one(xce_decision_t* d) +{ + if (d->op == XCE_DECISION_TRACE) { + repl_trace_on_trace_only(&g_sim, d); + return; + } + if (g_rs.mode != XCE_REPL_MODE_CONTINUE) { + sim_print_decision(d); + } + repl_trace_on_decision(&g_sim, d); +} + +/* An active collapsed range over idle rounds 3-4, which a flush prints. */ +static void open_idle_range(void) +{ + g_rs.collapse_active = true; + g_rs.collapse_start_round = 3; + g_rs.collapse_end_round = 4; +} + +static char* flush_line(void) +{ + char* out; + + cap_begin(); + repl_round_collapse_flush(&g_sim); + out = cap_end(); + TEST_ASSERT_TRUE(strlen(out) > 0); + return out; +} + +static char* concat3(const char* a, const char* b, const char* c) +{ + char* s = NULL; + + TEST_ASSERT_TRUE(asprintf(&s, "%s%s%s", a, b, c) >= 0); + return s; +} + +/* ---- session hooks (1.6, 8.5) -------------------------------------------- */ + +void test_session_begin_publishes_next_with_stamp(void) +{ + xce_sched_trace_ctl_t* ctl; + + cmd("trace on all"); + TEST_ASSERT_NOT_NULL(g_rs.trace.next); + ctl = repl_trace_settings_ctl(g_rs.trace.next); + ctl->position = 17; + g_rs.session_count = 9; + g_rs.trace.round_traced = true; + g_rs.trace.round_flushed = true; + + repl_trace_session_begin(&g_sim); + + TEST_ASSERT_TRUE(g_rs.trace.session_in_progress); + TEST_ASSERT_TRUE(g_rs.trace.cur == g_rs.trace.next); + TEST_ASSERT_TRUE(g_sim.core.trace_ctl == ctl); + TEST_ASSERT_EQUAL_UINT64(9, ctl->session_no); + TEST_ASSERT_EQUAL_INT(0, ctl->position); + TEST_ASSERT_FALSE(g_rs.trace.round_traced); + TEST_ASSERT_FALSE(g_rs.trace.round_flushed); + + repl_trace_session_end(&g_sim); + + TEST_ASSERT_NULL(g_sim.core.trace_ctl); + TEST_ASSERT_NULL(g_rs.trace.cur); + TEST_ASSERT_FALSE(g_rs.trace.session_in_progress); + TEST_ASSERT_NOT_NULL(g_rs.trace.next); /* still the next settings */ +} + +void test_session_begin_with_tracing_off_publishes_nothing(void) +{ + g_sim.core.trace_ctl = NULL; + repl_trace_session_begin(&g_sim); + + TEST_ASSERT_TRUE(g_rs.trace.session_in_progress); + TEST_ASSERT_NULL(g_rs.trace.cur); + TEST_ASSERT_NULL(g_sim.core.trace_ctl); + + repl_trace_session_end(&g_sim); + TEST_ASSERT_FALSE(g_rs.trace.session_in_progress); +} + +void test_command_during_session_applies_next_session(void) +{ + xce_repl_trace_settings_t* first; + + cmd("trace on all"); + first = g_rs.trace.next; + repl_trace_session_begin(&g_sim); + cmd("trace off"); /* 1.6: the session keeps its own settings */ + TEST_ASSERT_TRUE(g_rs.trace.cur == first); + TEST_ASSERT_TRUE(g_sim.core.trace_ctl == repl_trace_settings_ctl(first)); + repl_trace_session_end(&g_sim); + TEST_ASSERT_NULL(g_sim.core.trace_ctl); + + repl_trace_session_begin(&g_sim); + TEST_ASSERT_NULL(g_rs.trace.cur); + TEST_ASSERT_NULL(g_sim.core.trace_ctl); + repl_trace_session_end(&g_sim); +} + +void test_replaced_file_kept_until_session_end(void) +{ + fixture_decision_t f; + char* a; + char* b; + char* expect; + + cmd("trace on all file a.trace"); + repl_trace_session_begin(&g_sim); + cmd("trace on all file b.trace"); /* replaces next during the session */ + + TEST_ASSERT_TRUE(repl_trace_file_conflicts(&g_sim, "a.trace")); + trace_only_of(&f, JOB_A); + expect = render(f.d.trace); + cap_begin(); + drain_one(&f.d); + free(cap_end()); + TEST_ASSERT_NULL(f.d.trace); + + repl_trace_session_end(&g_sim); /* 8.5: a.trace is closed now */ + TEST_ASSERT_FALSE(repl_trace_file_conflicts(&g_sim, "a.trace")); + TEST_ASSERT_TRUE(repl_trace_file_conflicts(&g_sim, "b.trace")); + + a = read_file("a.trace"); + b = read_file("b.trace"); + TEST_ASSERT_EQUAL_STRING(expect, a); /* captured under a's settings */ + TEST_ASSERT_EQUAL_STRING("", b); + free(a); + free(b); + free(expect); +} + +/* ---- step mode (7.1, 7.2) ------------------------------------------------- + */ + +void test_step_mode_trace_follows_echo(void) +{ + fixture_decision_t f; + fixture_decision_t t; + char* out; + char* echo; + char* tr_d; + char* tr_t; + char* expect; + + cmd("trace on all"); + repl_trace_session_begin(&g_sim); + open_idle_range(); /* never flushed in step mode */ + + dispatch_of(&f, JOB_A); + trace_only_of(&t, JOB_B); + echo = echo_line("DISPATCH", JOB_A); + tr_d = render(f.d.trace); + tr_t = render(t.d.trace); + + cap_begin(); + drain_one(&f.d); + drain_one(&t.d); + out = cap_end(); + + expect = concat3(echo, tr_d, tr_t); + TEST_ASSERT_EQUAL_STRING(expect, out); + TEST_ASSERT_NULL(f.d.trace); /* handed to the store */ + TEST_ASSERT_NULL(t.d.trace); + TEST_ASSERT_TRUE(repl_trace_store_bytes(&g_rs.trace) > 0); + TEST_ASSERT_TRUE(g_rs.trace.round_traced); + TEST_ASSERT_FALSE(g_rs.trace.round_flushed); + TEST_ASSERT_TRUE(g_rs.collapse_active); + + repl_trace_session_end(&g_sim); + free(out); + free(echo); + free(tr_d); + free(tr_t); + free(expect); +} + +/* ---- continue mode (7.3) -------------------------------------------------- + */ + +void test_continue_mode_flush_echo_then_trace(void) +{ + fixture_decision_t f1; + fixture_decision_t f2; + fixture_decision_t t; + char* flush; + char* out; + char* e1; + char* e2; + char* tr1; + char* tr2; + char* trt; + char* part1; + char* part2; + char* expect; + + /* the flush line this range prints, taken from the real flush */ + open_idle_range(); + flush = flush_line(); + TEST_ASSERT_FALSE(g_rs.collapse_active); + + cmd("trace on all"); + g_rs.mode = XCE_REPL_MODE_CONTINUE; + repl_trace_session_begin(&g_sim); + open_idle_range(); + + dispatch_of(&f1, JOB_A); + pend_of(&f2, JOB_B); + trace_only_of(&t, JOB_B + 1); + e1 = echo_line("DISPATCH", JOB_A); + e2 = echo_line("PEND", JOB_B); + tr1 = render(f1.d.trace); + tr2 = render(f2.d.trace); + trt = render(t.d.trace); + + cap_begin(); + drain_one(&f1.d); + drain_one(&f2.d); + drain_one(&t.d); + out = cap_end(); + + part1 = concat3(flush, e1, tr1); + part2 = concat3(e2, tr2, trt); + expect = concat3(part1, part2, ""); + TEST_ASSERT_EQUAL_STRING(expect, out); + TEST_ASSERT_TRUE(g_rs.trace.round_traced); + TEST_ASSERT_TRUE(g_rs.trace.round_flushed); + TEST_ASSERT_FALSE(g_rs.collapse_active); + + repl_trace_session_end(&g_sim); + free(flush); + free(out); + free(e1); + free(e2); + free(tr1); + free(tr2); + free(trt); + free(part1); + free(part2); + free(expect); +} + +void test_continue_mode_trace_only_first_flushes_without_echo(void) +{ + fixture_decision_t t; + char* flush; + char* trt; + char* out; + char* expect; + + open_idle_range(); + flush = flush_line(); + + cmd("trace on all"); + g_rs.mode = XCE_REPL_MODE_CONTINUE; + repl_trace_session_begin(&g_sim); + open_idle_range(); + + trace_only_of(&t, JOB_A); + trt = render(t.d.trace); + cap_begin(); + drain_one(&t.d); + out = cap_end(); + + expect = concat3(flush, trt, ""); + TEST_ASSERT_EQUAL_STRING(expect, out); + + repl_trace_session_end(&g_sim); + free(flush); + free(trt); + free(out); + free(expect); +} + +/* ---- per-round flags ------------------------------------------------------ + */ + +void test_flags_reset_after_round_ended_in_step_mode(void) +{ + fixture_decision_t f; + fixture_decision_t g; + char* flush; + char* out; + + cmd("trace on all"); + + /* round 1: traced in continue mode, then a breakpoint and `step` */ + g_rs.mode = XCE_REPL_MODE_CONTINUE; + repl_trace_session_begin(&g_sim); + dispatch_of(&f, JOB_A); + cap_begin(); + drain_one(&f.d); + free(cap_end()); + TEST_ASSERT_TRUE(g_rs.trace.round_traced); + TEST_ASSERT_TRUE(g_rs.trace.round_flushed); + g_rs.mode = XCE_REPL_MODE_STEP; + repl_trace_session_end(&g_sim); + + /* round 2 begins in step mode: neither flag leaks into it */ + repl_trace_session_begin(&g_sim); + TEST_ASSERT_FALSE(g_rs.trace.round_traced); + TEST_ASSERT_FALSE(g_rs.trace.round_flushed); + repl_trace_session_end(&g_sim); + + /* round 3, continue mode: the first traced item flushes again */ + open_idle_range(); + flush = flush_line(); + g_rs.mode = XCE_REPL_MODE_CONTINUE; + repl_trace_session_begin(&g_sim); + open_idle_range(); + dispatch_of(&g, JOB_B); + cap_begin(); + drain_one(&g.d); + out = cap_end(); + TEST_ASSERT_TRUE(strncmp(out, flush, strlen(flush)) == 0); + repl_trace_session_end(&g_sim); + free(flush); + free(out); +} + +void test_step_mode_round_flags_reset_at_next_begin(void) +{ + fixture_decision_t f; + + cmd("trace on all"); + repl_trace_session_begin(&g_sim); + dispatch_of(&f, JOB_A); + cap_begin(); + drain_one(&f.d); + free(cap_end()); + TEST_ASSERT_TRUE(g_rs.trace.round_traced); + repl_trace_session_end(&g_sim); + + repl_trace_session_begin(&g_sim); + TEST_ASSERT_FALSE(g_rs.trace.round_traced); + TEST_ASSERT_FALSE(g_rs.trace.round_flushed); + repl_trace_session_end(&g_sim); +} + +/* ---- file copy (8.1) ------------------------------------------------------ + */ + +void test_file_copy_byte_equal_to_console(void) +{ + fixture_decision_t t1; + fixture_decision_t t2; + fixture_decision_t f; + char* console; + char* file; + char* echo; + char* tr_f; + char* expect; + + g_rs.units_mode = XCE_REPL_UNITS_HUMAN; + cmd("trace on all level full file a.trace"); + repl_trace_session_begin(&g_sim); + + /* trace-only records: the console shows exactly the trace */ + trace_only_of(&t1, JOB_A); + trace_only_of(&t2, JOB_B); + cap_begin(); + drain_one(&t1.d); + drain_one(&t2.d); + console = cap_end(); + file = read_file("a.trace"); /* flushed after every record */ + TEST_ASSERT_TRUE(strlen(console) > 0); + TEST_ASSERT_EQUAL_STRING(console, file); + free(file); + + /* a decision: the console adds only the echo line */ + dispatch_of(&f, JOB_A + 1); + echo = echo_line("DISPATCH", JOB_A + 1); + tr_f = render(f.d.trace); + free(console); + cap_begin(); + drain_one(&f.d); + console = cap_end(); + expect = concat3(echo, tr_f, ""); + TEST_ASSERT_EQUAL_STRING(expect, console); + file = read_file("a.trace"); + TEST_ASSERT_TRUE(strlen(file) >= strlen(tr_f)); + TEST_ASSERT_EQUAL_STRING(tr_f, file + strlen(file) - strlen(tr_f)); + + repl_trace_session_end(&g_sim); + free(console); + free(file); + free(echo); + free(tr_f); + free(expect); +} + +/* ---- error handling ------------------------------------------------------- + */ + +void test_file_write_error_reported_once_per_session(void) +{ + fixture_decision_t t1; + fixture_decision_t t2; + fixture_decision_t t3; + char* out; + const char* msg = "[sim] trace: write to /dev/full failed: "; + char* p; + + if (access("/dev/full", W_OK) != 0) { + TEST_IGNORE_MESSAGE("/dev/full is not available"); + } + cmd("trace on all file /dev/full"); + TEST_ASSERT_NOT_NULL(repl_trace_settings_file(g_rs.trace.next)); + + repl_trace_session_begin(&g_sim); + trace_only_of(&t1, JOB_A); + trace_only_of(&t2, JOB_B); + cap_begin(); + drain_one(&t1.d); + drain_one(&t2.d); + out = cap_end(); + p = strstr(out, msg); + TEST_ASSERT_NOT_NULL(p); + TEST_ASSERT_NULL(strstr(p + 1, msg)); /* once per session */ + TEST_ASSERT_NOT_NULL(strstr(out, strerror(ENOSPC))); + TEST_ASSERT_NULL(t2.d.trace); /* console and store carry on */ + free(out); + repl_trace_session_end(&g_sim); + + repl_trace_session_begin(&g_sim); + trace_only_of(&t3, JOB_A); + cap_begin(); + drain_one(&t3.d); + out = cap_end(); + TEST_ASSERT_NOT_NULL(strstr(out, msg)); /* reported again next session */ + free(out); + repl_trace_session_end(&g_sim); +} + +/* A record larger than the stdio buffer fails inside the renderer's own + * writes; the reported cause is still the real one (ENOSPC). */ +static void test_file_write_error_inside_render_reports_cause(void) +{ + fixture_decision_t t; + char* out; + int i; + + if (access("/dev/full", W_OK) != 0) { + TEST_IGNORE_MESSAGE("/dev/full is not available"); + } + cmd("trace on all file /dev/full"); + repl_trace_session_begin(&g_sim); + trace_only_of(&t, JOB_A); + for (i = 0; i < 900; i++) { + sched_trace_attempt_reasons(t.d.trace, NULL, 0, NULL, 0, NULL, 0); + } + cap_begin(); + drain_one(&t.d); + out = cap_end(); + TEST_ASSERT_NOT_NULL(strstr(out, "[sim] trace: write to /dev/full failed: ")); + TEST_ASSERT_NOT_NULL(strstr(out, strerror(ENOSPC))); + free(out); + repl_trace_session_end(&g_sim); +} + +int main(void) +{ + UNITY_BEGIN(); + RUN_TEST(test_session_begin_publishes_next_with_stamp); + RUN_TEST(test_session_begin_with_tracing_off_publishes_nothing); + RUN_TEST(test_command_during_session_applies_next_session); + RUN_TEST(test_replaced_file_kept_until_session_end); + RUN_TEST(test_step_mode_trace_follows_echo); + RUN_TEST(test_continue_mode_flush_echo_then_trace); + RUN_TEST(test_continue_mode_trace_only_first_flushes_without_echo); + RUN_TEST(test_flags_reset_after_round_ended_in_step_mode); + RUN_TEST(test_step_mode_round_flags_reset_at_next_begin); + RUN_TEST(test_file_copy_byte_equal_to_console); + RUN_TEST(test_file_write_error_inside_render_reports_cause); + RUN_TEST(test_file_write_error_reported_once_per_session); + return UNITY_END(); +}