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(); +}