/* * test_repl_step_verbosity.c - contract test for the interactive simulation * REPL's Event Echo Preamble Deduplicator component * (scheduler-sim-step-verbosity spec, task 1.1, Requirements 1 and 2): the * "[sim] t= () session=" preamble line * repl_print_event_summary() (repl_break.c) prints immediately before an * echoed event's own content line should print once per distinct * (rendered second-granularity timestamp, displayed session) run of * consecutive echoed events, not once per event -- leaving which events are * echoed, their own content, and their ordering completely unchanged. * * Split into its own file from the start (rather than appended to the * sibling test_repl_event_echo.c) -- design.md's File Structure Plan flags * that file's ~1000-line split trigger: it was already 705 lines * (scheduler-sim-repl-verbosity's Event Echo Gate tests) before this * feature began, and this task's six behavioral cases plus their own * preamble-construction helper would have pushed it well past that * threshold. Following this file family's established convention (see * test_repl_event_echo.c's own header comment on why IT split out of * test_repl_execution_control.c, and test_repl_round_rollup.c before it), * this file duplicates -- rather than shares via a new header -- the * pre-existing static fixture helpers it needs from test_repl_event_echo.c. * * Fixture strategy and white-box #include set: identical to * test_repl_event_echo.c/test_repl_round_rollup.c/ * test_repl_execution_control.c (see those files' own header comments) -- * this file exercises the same real sched_sim_driver_run() end-to-end, * forked-child, real-stdout-capture technique. Discrete-simulation * determinism note (research.md's own key finding, load-bearing for every * test below): `child_run_repl_and_exit()` sets args.sim_speed = 0, which * sim_set_virtual_clock() (sim.c) stores as core.speed_num == 0; with * speed_num == 0, xce_core_now()'s (core_clock.c) `elapsed * num / den` term * is always exactly zero, so xce_core_now() returns EXACTLY the raw * nanosecond `ts` value most recently passed to sim_advance_virtual_clock() * (sim_loop.c) for the event just decoded -- i.e. exactly the `ts` argument * each append_*_event() helper below is given, with no wall-clock jitter. * This is what makes it possible to construct exact, reproducible raw-ns * values below (including deliberately far-apart raw values that still * round to the identical displayed second) rather than merely hoping two * events land in the same second. * * bug-1595 jobid-safety discipline: NONE of this file's fixtures push, * mutate, or reference any job or jobid at all -- same discipline * test_repl_event_echo.c's own header comment documents, for the same * reason (every event used below, QUEUE_UPDATE/WORKERS_PUSH, is deliberately * job-free). * * THIS TASK (1.1) IS RED-PHASE ONLY: the preamble-dedup cache/short-circuit * under test does not exist yet in repl_print_event_summary() (repl_break.c) * today -- that function unconditionally builds and prints the preamble on * every single call, with no reference to any "last printed" state on * xce_sched_repl_state_s (task 1.2, a separate later task, adds both the * cache fields and the short-circuit). Every symbol this file references * already exists today, so every test below builds and links cleanly but * FAILS certain of its own runtime assertions -- specifically, every * assertion that a SECOND same-context event's preamble is ABSENT. Verified * concretely (not assumed) against a real incremental ASAN build before * this task was reported done -- see this task's own Status Report. * * Assumed output contract this file pins (matches design.md's Event Echo * Preamble Deduplicator component and test_repl_event_echo.c's own * "Assumed output contract" precedent): * - repl_print_event_summary() prints "[sim] t= () * session=\n" where is the exact raw nanosecond value * xce_core_now() returns for that event (see the determinism note * above), is that same value rendered via * repl_format_ts_human() to second granularity, and is * rs->session_count + 1 at the moment the event is echoed. * - TARGET (post task 1.2) behavior this file's RED assertions pin: that * preamble line is printed only when or differs from the * immediately preceding ECHOED event's own printed / (or * when there is no preceding echoed event this session) -- never based * on the raw value, which may legitimately differ between two * events sharing the same displayed / (Requirement 1.3). * - An event's own content line (the existing "[sim] event: ..." switch * in repl_print_event_summary()) is unaffected either way -- always * printed exactly as today, in the same relative order (Requirement * 1.4, 2.2). * - Tests use strstr()/pointer-order comparisons on captured real stdout, * the same technique test_repl_event_echo.c's own tests establish. */ #include #include #include #include #include #include #include #include #include #include #include #include "controller.capnp.h" #include "kvmgr.h" #include "scheduler.h" #include "xstring.h" /* Pull in the real functions under test into this TU (white-box #include, * same convention as test_repl_event_echo.c/test_repl_round_rollup.c/ * test_repl_execution_control.c/test_repl_breakpoints_inspection.c). */ #include "../src/core.c" #include "../src/core_clock.c" #include "../src/core_events.c" #include "../src/core_session.c" #include "../src/decision.c" #include "../src/plugin.c" #include "../src/plugins/builtin_fcfs.c" #include "../src/recording.c" #include "../src/recording_session.c" #include "../src/repl.c" #include "../src/repl_fmt.c" #include "../src/repl_rollup.c" #include "../src/repl_break.c" #include "../src/repl_info.c" #include "../src/repl_params.c" #include "../src/sim.c" #include "../src/sim_loop.c" #include "../src/sim_picker.c" /* bug-1567: sched_sim_driver_run() now calls sim_bootstrap_picker() (sim_loop.c-cap sibling) as an extern -- undefined reference at link time otherwise */ #include "../src/sim_limit.c" /* bug-1825: sched_sim_driver_run() now also calls sim_bootstrap_limit_plugin() (sim_loop.c-cap sibling, sim_picker.c's own bug-1567 precedent) as an extern -- undefined reference at link time otherwise */ #include "../src/sim_record.c" #include "../src/sim_verify.c" #include "../src/snapshot.c" #include "../src/snapshot_load.c" #include "../src/snapshot_wire.c" void kill_sched_job(void* arg) { (void)arg; } void kill_sched_queue(void* arg) { (void)arg; } void kill_sched_worker(void* arg) { (void)arg; } void kill_sched_user(void* arg) { (void)arg; } void kill_sched_project(void* arg) { (void)arg; } void kill_sched_resval(xce_val_t* val) { (void)val; } /* repl_info.c (scheduler-sim-diagnostics spec, task 2.1) now calls * limit_get_configured_limits() (plugins/limit.c, not part of this TU) to * resolve `info limit`'s name/all argument -- link-satisfying stub only, * same rationale as kill_sched_job()/kill_sched_resval() above; this * file's own fixtures never register the limit plugin, so NULL * (limit_get_configured_limits()'s own documented "plugin absent" return) * is also the behaviorally correct answer here, not just a link * placeholder. repl_info_limit() itself is not yet wired into * repl_cmd_info() (task 4), so no test in this file can reach it anyway. */ var limit_get_configured_limits(xce_sched_core_t* core) { (void)core; return NULL; } /* scheduler-sim-diagnostics spec, task 3.1: repl_info.c now also calls * limit_get_usage_instances() (plugins/limit.c, not part of this TU) to * read a limit's live usage instances -- identical link-satisfying stub, * same rationale as limit_get_configured_limits() immediately above; this * file's own fixtures never register the limit plugin, so NULL * (limit_get_usage_instances()'s own documented "plugin absent" return) is * also the behaviorally correct answer here, not just a link placeholder. */ var limit_get_usage_instances(xce_sched_core_t* core) { (void)core; return NULL; } /* scheduler-sim-diagnostics spec, task 6 (bug-1825): sim_loop.c's * sched_sim_driver_run() now also calls sim_bootstrap_limit_plugin() * (sim_limit.c, pulled into this TU via the #include above), which in * turn calls limit_new_plugin() (plugins/limit.c, not part of this TU) -- * identical link-satisfying stub rationale as limit_get_configured_ * limits()/limit_get_usage_instances() immediately above. Returning NULL * here is also the behaviorally correct answer, not just a link * placeholder: sim_bootstrap_limit_plugin() already handles a NULL * limit_new_plugin() return gracefully (logs an ERROR, registers nothing, * returns) -- the exact same "out of memory" path sim_bootstrap_picker() * (sim_picker.c) takes for a NULL builtin_fcfs_new_plugin() -- so this * file's fixtures simply end up with no limit plugin registered, same * observable state as before this task. */ xce_sched_plugin_t* limit_new_plugin(void) { return NULL; } /* limit_seed_config() (plugins/limit.c, not part of this TU) -- bug-1825 * remediation round 2's new honestly-typed config-seed entry point. * sim_bootstrap_limit_plugin() (sim_limit.c) only calls it after * plugin_register_core() has already succeeded against a real, non-NULL * limit_new_plugin() plugin -- unreachable in this file since the * limit_new_plugin() stub immediately above always returns NULL, but the * symbol must still resolve at link time. Same link-satisfying-stub * rationale as limit_new_plugin() immediately above. */ int limit_seed_config(xce_sched_plugin_t* plugin, xce_sched_core_t* core, xce_conf4sched_t* config) { (void)plugin; (void)core; (void)config; return 0; } /* resource-accounting.md's reconciliation (resource.c, not linked here -- * this file only #includes core_events.c). core_events.c's * XCE_CORE_EVENT_JOB_RUSAGE handler calls this whenever job->accounts != * NULL; link-satisfying stub only, same rationale as every other stub in * this block (see test_repl_event_echo.c's identical stub). */ int sched_reconcile_job_resource_usage(xce_sched_core_t* c, xce_job_account_t* a, xce_job_rusages_t* r) { (void)c; (void)a; (void)r; return 0; } void sched_worker_release_host_ctx(xce_sched_worker_t* w) { (void)w; } int sched_fill_limit_requests(xce_sched_alloc_req_t* alloc_req, xlist_t* limits, xlist_t* rusages, int nhosts, int nslots) { (void)alloc_req; (void)limits; (void)rusages; (void)nhosts; (void)nslots; return 0; } /* sched_sim_driver_run()'s (sim_loop.c, scheduler-sim-decision-parity task * 2.1) new round-boundary call to the relocated sched_account_jobs() * (core.h) -- a no-op stand-in here since this file does not link * scheduler.c/resource.c, same rationale test_repl_event_echo.c's own copy * documents. */ int sched_account_jobs(xce_sched_core_t* core) { (void)core; return 0; } /* bug-1836 (scheduler-driver-equivalence fix, Recorded-Decision * Reconciliation capacity gate): link-satisfying stubs, mirroring this * file's existing sched_account_jobs() no-op precedent immediately above -- * sim_loop.c's sim_reconcile_unaccounted_jobs() now also calls * sched_check_host_satisfy()/sched_check_shared_satisfy() (resource.c) to * re-validate a recorded decision against live capacity, and * sched_charge_account() (resource.c) to keep that check's own view of * capacity up to date across multiple candidates in the same round. This * file never exercises real resource contention (same rationale as the * existing sched_account_jobs()/sched_ctx_get_uncomit_host() no-ops), so * the satisfy checks trivially always succeed and the charge call is a * no-op. */ int sched_check_host_satisfy(xce_sched_core_t* core, xce_sched_worker_t* w, xvec_t* uncomitted, xvec_idval_t* wanted, xvec_idval_t* unmeet) { (void)core; (void)w; (void)uncomitted; (void)wanted; (void)unmeet; return 1; } int sched_check_shared_satisfy(xce_sched_core_t* core, xvec_t* uncomitted, xvec_idval_t* wanted, xvec_idval_t* unmeet) { (void)core; (void)uncomitted; (void)wanted; (void)unmeet; return 1; } int sched_charge_account(xce_sched_core_t* core, xce_job_account_t* acct) { (void)core; (void)acct; return 0; } int sched_uncharge_account(xce_sched_core_t* core, xce_job_account_t* acct) { (void)core; (void)acct; return 0; } /* Real reimplementation of schedobj.c's sched_resolve_job_picker -- same * copy test_repl_event_echo.c/test_repl_round_rollup.c/ * test_repl_execution_control.c/test_sim_alt_events.c/test_sim_verify.c/ * test_sim_event_loop.c each carry (schedobj.c is not linked here: it would * need plugin_register(), which requires a genuine xce_scheduler_t* neither * this file's fixtures nor sim_loop.c's own core-scoped registration path * have, Req 5 AC 17). */ int sched_resolve_job_picker(xce_sched_core_t* core, xce_sched_plugin_t** out) { xce_sched_plugin_t* plugin = NULL; int rc = 0; if ((core == NULL) || (out == NULL)) { return -EINVAL; } *out = NULL; if (core->job_pick_plugin == NULL) { return -EINVAL; } lock(core->plugins, RTTI_LOCK_READ); rc = key_find(core->plugins, core->job_pick_plugin, (void**)&plugin); unlock(core->plugins); if (rc <= 0) { return (rc < 0) ? rc : -ENOENT; } if ((plugin == NULL) || (plugin->picker_iface == NULL) || (plugin->picker_iface->next_job == NULL) || (plugin->picker_iface->begin_session == NULL) || (plugin->picker_iface->end_session == NULL) || (plugin->picker_iface->on_dispatch == NULL) || (plugin->picker_iface->on_pend == NULL)) { return -EINVAL; } *out = plugin; return 0; } /* scheduler-sim-live-allocation spec, task 4.1: sim_loop.c's real * sched_sim_driver_run() (white-box #include'd into this TU above) now * spawns sched_job_picker()/sched_allocator() (sched_election.c) directly * instead of its own, now-removed sim_picker_thread_fn() -- an undefined * reference at link time in this white-box TU otherwise, since * sched_election.c's own sched_allocator() calls the REAL * sched_make_allocation()/sched_commit_decision() (scheduler.c), neither * part of this file's own hand-picked white-box #include set (this file's * own header comment lists that set). This file's own test(s) do not * exercise genuine resource-matching allocation, so this link-satisfying * pair faithfully reproduces the exact PEND-only contract the REMOVED * sim_picker_thread_fn() itself used to provide -- split across the SAME * two-thread jbuf hand-off the real production pair now uses (one * producer, one consumer, matching the project's jbuf capacity-1 * rendezvous invariant) instead of the old single fused thread -- so this * file's own existing assertions are unaffected by this task's production * change. Genuine resource-based dispatch through the real, unmodified * sched_job_picker()/sched_allocator() pair is proved separately by * test_sim_live_allocation.c (task 4.1's own dedicated fixture, which * links the real scheduler_srcs instead of white-boxing individual files, * precisely so it can reach the real allocation chain this stub * deliberately does not). */ void* sched_job_picker(void* arg) { xce_sched_core_t* core = (xce_sched_core_t*)arg; xce_sched_plugin_t* picker = NULL; for (;;) { int go = 0; uint64_t jobid = 0; cbuf_get(&(core->wbuf), &go); if (sched_resolve_job_picker(core, &picker) < 0) { jobid = 0; cbuf_put(&(core->jbuf), &jobid); continue; } picker->picker_iface->begin_session(picker); for (;;) { xce_sched_job_t* job = picker->picker_iface->next_job(picker); if (job == NULL) { break; } jobid = job->jobid; cbuf_put(&(core->jbuf), &jobid); } jobid = 0; cbuf_put(&(core->jbuf), &jobid); picker->picker_iface->end_session(picker); } return NULL; } void* sched_allocator(void* arg) { xce_sched_core_t* core = (xce_sched_core_t*)arg; xce_sched_plugin_t* picker = NULL; for (;;) { uint64_t jobid = 0; xce_decision_t* decision = NULL; xce_sched_job_t* job; cbuf_get(&(core->jbuf), &jobid); if (jobid == 0) { decision = NULL; cbuf_put(&(core->decisions), &decision); continue; } job = sched_get_job(core, jobid); if (job == NULL) { continue; } (void)sched_resolve_job_picker(core, &picker); if (picker != NULL) { picker->picker_iface->on_pend(picker, job->jobid); } decision = make_pend_decision(make_pendreason(job->jobid)); cbuf_put(&(core->decisions), &decision); } return NULL; } /* scheduler-sim-live-allocation spec, task 4.1 (bug-1829 fix): sim_loop.c's * real sched_sim_driver_run() (white-box #include'd into this TU above) now * also calls sim_bootstrap_seqjob_allocator()/sim_bootstrap_parjob_ * allocator() (sim_alloc.c) -- undefined references at link time in this * white-box TU otherwise, since neither symbol is part of this file's own * hand-picked white-box #include set. This file's own test(s) exercise the * link-satisfying sched_job_picker()/sched_allocator() stub pair above * (which never reaches real primary allocation), so a true no-op is the * correct, behavior-preserving stand-in here -- the real bootstrap logic is * exercised separately by test_sim_live_allocation.c (task 4.1's own * dedicated fixture, which links the real scheduler_srcs). */ void sim_bootstrap_seqjob_allocator(xce_sched_sim_driver_t* sim) { (void)sim; } void sim_bootstrap_parjob_allocator(xce_sched_sim_driver_t* sim) { (void)sim; } void setUp(void) { return; } void tearDown(void) { return; } /* ---------------------------------------------------------------------- */ /* Fixture helpers -- duplicated from test_repl_event_echo.c (itself */ /* duplicated from test_repl_round_rollup.c/test_repl_execution_control.c),*/ /* per this file family's established split convention (see header comment */ /* above): copied, not shared via a new header. */ /* ---------------------------------------------------------------------- */ static void make_tmp_dir(char* out, size_t out_len, const char* suffix) { char tmpl[PATH_MAX]; snprintf(tmpl, sizeof(tmpl), "/tmp/sched_replexec%s_XXXXXX", suffix); TEST_ASSERT_NOT_NULL(mkdtemp(tmpl)); TEST_ASSERT_TRUE(strlen(tmpl) < out_len); strcpy(out, tmpl); } static void build_fixture_scheduler(xce_scheduler_t* sched, char* record_dir) { int rc; memset(sched, 0, sizeof(*sched)); mylock_init(&(sched->record_lock)); rc = xce_sched_core_init(&(sched->core)); TEST_ASSERT_EQUAL_INT(0, rc); sched->core.job_pick_plugin = (char*)"builtin_fcfs"; sched->record_dir = record_dir; } static FILE* write_header_and_snapshot(char* out_path, size_t out_path_len, const char* suffix) { char record_dir[PATH_MAX]; xce_scheduler_t sched; int rc; make_tmp_dir(record_dir, sizeof(record_dir), suffix); build_fixture_scheduler(&sched, record_dir); rc = sched_record_start(&sched, "fixture.replay"); TEST_ASSERT_EQUAL_INT(0, rc); TEST_ASSERT_TRUE(strlen(sched.record_file_path) < out_path_len); strcpy(out_path, sched.record_file_path); return sched.record_file; } static void append_queue_update_event(FILE* f, uint64_t ts, const char* queue_name) { xce_queue_t queue; replay_event_t src; struct capn c; struct capn_segment* cs; ReplayEvent_ptr p; memset(&queue, 0, sizeof(queue)); queue.queue = (char*)queue_name; queue.status = QUEUE_STAT_OPEN; queue.priority = 1; memset(&src, 0, sizeof(src)); src.ts = ts; src.body_which = ReplayEvent_body_queueUpdate; src.body.queue_update = &queue; capn_init_malloc(&c); cs = capn_root(&c).seg; encode_ReplayEvent_ptr(cs, &p, &src); capn_setp(capn_root(&c), 0, p.p); TEST_ASSERT_EQUAL_INT(0, write_capnp_message(f, &c)); capn_free(&c); } /* append_workers_push_event - a structural event (WORKERS_PUSH, per * design.md's Event Echo Gate classification list, unmodified by this * spec), encoded the same minimal-zeroed-wire-struct way * test_repl_event_echo.c's own copy of this helper builds it -- only the * fields core_upsert_worker()/core_build_worker() (core_events.c) actually * read (w->name, w->status, w->nresvals_to_sched) are set; everything else * stays zeroed/NULL. Deliberately job-free -- see this file's own header * comment on bug-1595 jobid safety. */ static void append_workers_push_event(FILE* f, uint64_t ts, const char* worker_name) { xce_worker_t worker; xce_worker_t* workers[1]; xce_workers_data_t workers_data; replay_event_t src; struct capn c; struct capn_segment* cs; ReplayEvent_ptr p; memset(&worker, 0, sizeof(worker)); worker.name = (char*)worker_name; workers[0] = &worker; memset(&workers_data, 0, sizeof(workers_data)); workers_data.n_total = 1; workers_data.count = 1; workers_data.workers = workers; memset(&src, 0, sizeof(src)); src.ts = ts; src.body_which = ReplayEvent_body_workersPush; src.body.workers_push = &workers_data; capn_init_malloc(&c); cs = capn_root(&c).seg; encode_ReplayEvent_ptr(cs, &p, &src); capn_setp(capn_root(&c), 0, p.p); TEST_ASSERT_EQUAL_INT(0, write_capnp_message(f, &c)); capn_free(&c); } static void append_replay_session(FILE* f, uint64_t begin_round) { struct capn c; struct capn_segment* cs; ReplaySession_ptr sp; capn_init_malloc(&c); cs = capn_root(&c).seg; sp = new_ReplaySession(cs); ReplaySession_set_beginRound(sp, begin_round); capn_setp(capn_root(&c), 0, sp.p); TEST_ASSERT_EQUAL_INT(0, write_capnp_message(f, &c)); capn_free(&c); } static void append_end_of_stream_marker(FILE* f) { replay_event_t src; struct capn c; struct capn_segment* cs; ReplayEvent_ptr p; memset(&src, 0, sizeof(src)); src.body_which = ReplayEvent_body_endSession; capn_init_malloc(&c); cs = capn_root(&c).seg; encode_ReplayEvent_ptr(cs, &p, &src); capn_setp(capn_root(&c), 0, p.p); TEST_ASSERT_EQUAL_INT(0, write_capnp_message(f, &c)); capn_free(&c); } static void write_text_file(const char* path, const char* content) { FILE* f = fopen(path, "w"); TEST_ASSERT_NOT_NULL(f); TEST_ASSERT_TRUE(fputs(content, f) >= 0); fclose(f); } static char* read_whole_file(const char* path) { FILE* f = fopen(path, "rb"); long len; char* buf; 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*)malloc((size_t)len + 1); TEST_ASSERT_NOT_NULL(buf); if (len > 0) { TEST_ASSERT_EQUAL_INT((int)len, (int)fread(buf, 1, (size_t)len, f)); } buf[len] = '\0'; fclose(f); return buf; } /* child_run_repl_and_exit / run_repl_fixture_and_capture - the same fork/ * freopen/waitpid/capture shape test_repl_event_echo.c's own pair * establishes: run a scripted command sequence to completion against a real * sched_sim_driver_run(), capturing real stdout. args.sim_speed = 0 below is * this file's own load-bearing determinism note (see header comment) -- it * is what makes xce_core_now() return EXACTLY each event's own `ts`. */ static void child_run_repl_and_exit(const char* replay_path, const char* script_path, const char* capture_path) { xce_sched_sim_driver_t sim; sched_sim_args_t args; if (freopen(script_path, "r", stdin) == NULL) { _exit(120); } if (freopen(capture_path, "w", stdout) == NULL) { _exit(121); } memset(&sim, 0, sizeof(sim)); memset(&args, 0, sizeof(args)); args.replay_path = replay_path; args.sim_start_ts = SCHED_SIM_START_TS_LATEST; args.sim_speed = 0; args.interactive = true; (void)sched_sim_driver_run(&sim, &args); fflush(stdout); _exit(111); /* unreachable -- the script's `quit` must already have * exited */ } static char* run_repl_fixture_and_capture(const char* replay_path, const char* script, const char* aux_suffix) { char aux_dir[PATH_MAX]; char script_path[PATH_MAX]; char capture_path[PATH_MAX]; pid_t pid; int status; make_tmp_dir(aux_dir, sizeof(aux_dir), aux_suffix); snprintf(script_path, sizeof(script_path), "%s/script.txt", aux_dir); snprintf(capture_path, sizeof(capture_path), "%s/capture.out", aux_dir); write_text_file(script_path, script); pid = fork(); TEST_ASSERT_TRUE_MESSAGE(pid >= 0, "fork() must succeed"); if (pid == 0) { child_run_repl_and_exit(replay_path, script_path, capture_path); _exit(112); /* unreachable -- child_run_repl_and_exit never returns */ } TEST_ASSERT_EQUAL_INT_MESSAGE(pid, waitpid(pid, &status, 0), "waitpid must reap the REPL child"); TEST_ASSERT_TRUE_MESSAGE(WIFEXITED(status), "the REPL child must exit normally via quit's " "exit(0)"); TEST_ASSERT_EQUAL_INT(0, WEXITSTATUS(status)); return read_whole_file(capture_path); } /* build_preamble_line - constructs the EXACT text * repl_print_event_summary() (repl_break.c) prints for one event's preamble * given its raw nanosecond timestamp and displayed session number, using * the real repl_format_ts_human() (pulled into this TU verbatim via * repl_fmt.c's white-box #include -- the same renderer production uses, * never a hand-rolled ISO8601 string) so this helper can never silently * drift from what repl_print_event_summary() actually emits. Deliberately * excludes the trailing '\n' so the result is a valid strstr() needle * immediately followed by that event's own content line. Because this * needle embeds the exact raw `ts`, it unambiguously targets ONE specific * event's preamble even when a neighboring event shares the same rendered * (, session) pair but a different raw ts. */ static void build_preamble_line(char* out, size_t outsz, uint64_t raw_ts_ns, uint64_t session_num) { char ts_human[32]; repl_format_ts_human(raw_ts_ns, ts_human, sizeof(ts_human)); snprintf(out, outsz, "[sim] t=%llu (%s) session=%llu", (unsigned long long)raw_ts_ns, ts_human, (unsigned long long)session_num); } /* ---------------------------------------------------------------------- */ /* Test 1: two consecutive echoed events sharing the same rendered */ /* timestamp and session -- the second's preamble must be OMITTED, while */ /* both events' own content lines stay present and in order (Requirements */ /* 1.1, 1.2, 1.4, 2.2). THE primary RED case: today's REPL prints both */ /* preambles unconditionally. */ /* ---------------------------------------------------------------------- */ static void test_second_event_with_same_rendered_context_omits_preamble(void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char preamble1[96]; char preamble2[96]; char* preamble1_pos; char* preamble2_pos; char* content1_pos; char* content2_pos; f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svsamectx"); TEST_ASSERT_NOT_NULL(f); /* Two consecutive routine events (QUEUE_UPDATE), both decoded before * the first ReplaySession boundary -- both echoed with the SAME * displayed session (rs->session_count + 1 == 1 for both, since no * ReplaySession has been processed yet) and the SAME rendered second * (both raw ts values floor to second 0 via repl_format_ts_human()'s * ns/1e9 truncation). "step" (default N=1) puts the REPL in STEP mode * for the whole round, so both routine events are echoed. */ append_queue_update_event(f, 1000ULL, "queueA"); append_queue_update_event(f, 2000ULL, "queueB"); append_replay_session(f, 2000000000ULL); /* round 1: idle */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture(replay_path, "step\nquit\n", "_svsamectxaux"); build_preamble_line(preamble1, sizeof(preamble1), 1000ULL, 1ULL); build_preamble_line(preamble2, sizeof(preamble2), 2000ULL, 1ULL); preamble1_pos = strstr(captured, preamble1); preamble2_pos = strstr(captured, preamble2); content1_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=queueA"); content2_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=queueB"); TEST_ASSERT_NOT_NULL_MESSAGE( preamble1_pos, "the FIRST echoed event of a fresh REPL session must always print " "its own preamble -- there is no preceding echoed event yet to " "compare against (Requirement 1.2)"); TEST_ASSERT_NOT_NULL_MESSAGE( content1_pos, "event1's own content line must appear regardless of the preamble " "decision (Requirement 1.4)"); TEST_ASSERT_NOT_NULL_MESSAGE( content2_pos, "event2's own content line must appear regardless of the preamble " "decision (Requirement 1.4)"); /* THE RED ASSERTION (Requirement 1.1): event2's rendered timestamp and * displayed session are IDENTICAL to event1's -- the immediately * preceding echoed event -- so event2's preamble line must be OMITTED. * Today's repl_print_event_summary() prints it unconditionally on * every call, so preamble2_pos is found (non-NULL) against today's * code, when it must be NULL (absent) once task 1.2 lands. */ TEST_ASSERT_NULL_MESSAGE( preamble2_pos, "event2 shares its immediately preceding echoed event's rendered " "timestamp and session -- its preamble line must be OMITTED " "(Requirement 1.1); expected to fail against today's REPL, which " "prints the preamble unconditionally before every echoed event"); TEST_ASSERT_TRUE_MESSAGE( preamble1_pos < content1_pos, "event1's preamble must still precede its own content line"); TEST_ASSERT_TRUE_MESSAGE( content1_pos < content2_pos, "event content lines must stay in their original relative order " "regardless of any preamble's presence or absence (Requirement " "2.2)"); free(captured); printf( "test_second_event_with_same_rendered_context_omits_preamble: " "PASS\n"); } /* ---------------------------------------------------------------------- */ /* Test 2: two consecutive echoed events spanning a session boundary -- */ /* BOTH must print their own full preamble (Requirement 1.2). */ /* ---------------------------------------------------------------------- */ static void test_events_across_session_boundary_both_print_own_preamble(void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char preamble1[96]; char preamble2[96]; char* preamble1_pos; char* preamble2_pos; f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svsessbound"); TEST_ASSERT_NOT_NULL(f); /* event1 is decoded before round 1's ReplaySession boundary, so it is * echoed with session = rs->session_count + 1 == 0 + 1 == 1. The first * "step" command processes exactly round 1 (echoing event1, then * pausing right after round 1's decisions drain -- xce_repl_ * post_session_pause()/repl_should_pause(), repl.c). event2 is only * decoded once the SECOND "step" command resumes the replay stream; by * then round 1's begin_round hook (xce_repl_on_begin_round(), * repl_break.c) has already incremented rs->session_count to 1, so * event2 is echoed with session == 1 + 1 == 2 -- a genuine session * boundary between these two consecutive echoed events, with no other * echoed event between them. */ append_queue_update_event(f, 1000ULL, "queueA"); append_replay_session(f, 2000000000ULL); /* round 1 boundary */ append_queue_update_event(f, 2500000000ULL, "queueB"); append_replay_session(f, 3000000000ULL); /* round 2 boundary */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture( replay_path, "step\nstep\nquit\n", "_svsessboundaux"); build_preamble_line(preamble1, sizeof(preamble1), 1000ULL, 1ULL); build_preamble_line(preamble2, sizeof(preamble2), 2500000000ULL, 2ULL); preamble1_pos = strstr(captured, preamble1); preamble2_pos = strstr(captured, preamble2); TEST_ASSERT_NOT_NULL_MESSAGE( preamble1_pos, "event1 (session 1) must print its own full preamble"); TEST_ASSERT_NOT_NULL_MESSAGE( preamble2_pos, "event2's displayed session (2) differs from event1's (1) -- a " "session boundary occurred between these two consecutive echoed " "events, so event2 must print its own full preamble rather than " "being deduped against event1 (Requirement 1.2)"); TEST_ASSERT_TRUE_MESSAGE(preamble1_pos < preamble2_pos, "the two sessions' preambles must appear in " "their original relative order"); free(captured); printf( "test_events_across_session_boundary_both_print_own_preamble: " "PASS\n"); } /* ---------------------------------------------------------------------- */ /* Test 3 (the critical nuance, research.md's Design Decision): two */ /* consecutive echoed events whose RAW high-resolution timestamps differ */ /* substantially, but whose RENDERED (second-granularity) timestamp and */ /* session are identical -- the second's preamble must STILL be omitted. */ /* This is the case that would fail if a future implementation keyed dedup */ /* on the raw xce_core_now() value instead of the rendered display value */ /* (Requirement 1.3). */ /* ---------------------------------------------------------------------- */ static void test_dedup_key_is_rendered_timestamp_not_raw_nanoseconds(void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char ts_human1[32]; char ts_human2[32]; char preamble1[96]; char preamble2[96]; char* preamble1_pos; char* preamble2_pos; char* content1_pos; char* content2_pos; /* Fixture premise check (not a test of production behavior): raw ts * values 1ns and 999,999,999ns are as far apart as two values can be * while still flooring to the SAME displayed second under * repl_format_ts_human()'s ns/1e9 truncation -- confirms this fixture * genuinely exercises "raw differs, rendered doesn't", not merely two * values that happen to be numerically close. */ repl_format_ts_human(1ULL, ts_human1, sizeof(ts_human1)); repl_format_ts_human(999999999ULL, ts_human2, sizeof(ts_human2)); TEST_ASSERT_EQUAL_STRING_MESSAGE( ts_human1, ts_human2, "fixture premise: raw ts 1ns and 999999999ns must render to the " "IDENTICAL displayed second for this test to exercise Requirement " "1.3's actual nuance"); f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svrawnsdiff"); TEST_ASSERT_NOT_NULL(f); append_queue_update_event(f, 1ULL, "queueA"); append_queue_update_event(f, 999999999ULL, "queueB"); append_replay_session(f, 2000000000ULL); /* round 1: idle */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture(replay_path, "step\nquit\n", "_svrawnsdiffaux"); build_preamble_line(preamble1, sizeof(preamble1), 1ULL, 1ULL); build_preamble_line(preamble2, sizeof(preamble2), 999999999ULL, 1ULL); preamble1_pos = strstr(captured, preamble1); preamble2_pos = strstr(captured, preamble2); content1_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=queueA"); content2_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=queueB"); TEST_ASSERT_NOT_NULL_MESSAGE(preamble1_pos, "event1 (first echo) must print its own " "preamble"); TEST_ASSERT_NOT_NULL_MESSAGE(content1_pos, "event1's content line must " "appear"); TEST_ASSERT_NOT_NULL_MESSAGE(content2_pos, "event2's content line must " "appear"); /* THE RED ASSERTION (Requirement 1.3): event2's raw ts (999999999ns) * differs enormously from event1's (1ns) -- almost a full second apart * -- yet both render to the identical displayed second and session. * The dedup key must be the RENDERED pair, never the raw value, so * event2's preamble must still be omitted. Today's code prints a fresh * preamble unconditionally on every call (using the raw, always-unique * value), so this fails against today's REPL. */ TEST_ASSERT_NULL_MESSAGE( preamble2_pos, "event2's raw nanosecond timestamp genuinely differs from event1's, " "but its RENDERED timestamp and session are identical -- its " "preamble must still be omitted (Requirement 1.3); a naive " "raw-nanosecond dedup key would wrongly print this preamble since " "raw t values essentially never repeat"); TEST_ASSERT_TRUE_MESSAGE(content1_pos < content2_pos, "event content lines must stay in their " "original relative order (Requirement 2.2)"); free(captured); printf( "test_dedup_key_is_rendered_timestamp_not_raw_nanoseconds: PASS\n"); } /* ---------------------------------------------------------------------- */ /* Test 4: the very first echoed event of a fresh REPL session always */ /* prints its preamble -- there is no preceding echoed event to compare */ /* against (Requirement 1.2). Uses a structural event (WORKERS_PUSH) under */ /* `continue` so it also doubles as a baseline outside step mode. */ /* ---------------------------------------------------------------------- */ static void test_first_echoed_event_in_fresh_session_prints_preamble(void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char preamble1[96]; char* preamble1_pos; char* content1_pos; f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svfirstecho"); TEST_ASSERT_NOT_NULL(f); append_workers_push_event(f, 1234ULL, "workerOnly"); append_replay_session(f, 2000000000ULL); /* round 1: idle */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture(replay_path, "continue\nquit\n", "_svfirstechoaux"); build_preamble_line(preamble1, sizeof(preamble1), 1234ULL, 1ULL); preamble1_pos = strstr(captured, preamble1); content1_pos = strstr( captured, "[sim] event: WORKERS_PUSH nworkers=1 names=[workerOnly]"); TEST_ASSERT_NOT_NULL_MESSAGE( preamble1_pos, "the very first echoed event of a fresh REPL session must print " "its preamble -- no preceding echoed event exists this session to " "compare its rendered context against (Requirement 1.2)"); TEST_ASSERT_NOT_NULL_MESSAGE(content1_pos, "the event's own content line must appear"); TEST_ASSERT_TRUE_MESSAGE(preamble1_pos < content1_pos, "the preamble must precede the event's own " "content line"); free(captured); printf( "test_first_echoed_event_in_fresh_session_prints_preamble: PASS\n"); } /* ---------------------------------------------------------------------- */ /* Test 5: a structural event echoed under `continue` mode after a */ /* stretch of suppressed routine events follows the SAME dedup rule as any */ /* other echoed event -- exercised at both ends: the first structural */ /* event has no preceding ECHOED event (the suppressed routine events */ /* never reached repl_print_event_summary() at all, so they never touched */ /* the dedup cache) and so prints its preamble; a second structural event */ /* immediately after it, sharing the same rendered context, has its */ /* preamble omitted exactly as Test 1 exercises in step mode (Requirements */ /* 1.1, 1.2). */ /* ---------------------------------------------------------------------- */ static void test_structural_event_after_suppressed_routine_events_follows_dedup_rule( void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char preambleA[96]; char preambleB[96]; char* preambleA_pos; char* preambleB_pos; char* contentA_pos; char* contentB_pos; f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svcontsuppress"); TEST_ASSERT_NOT_NULL(f); /* Two routine QUEUE_UPDATE events -- suppressed entirely under * `continue` mode (Event Echo Gate, scheduler-sim-repl-verbosity * Requirement 1), so they never reach repl_print_event_summary() and * can never contribute to (or be affected by) the preamble dedup * cache. */ append_queue_update_event(f, 500ULL, "normal1"); append_queue_update_event(f, 600ULL, "normal2"); /* Two structural WORKERS_PUSH events sharing the same rendered second * (both floor to second 0) and the same displayed session (both * decoded before the first ReplaySession boundary, so both are echoed * with session == 0 + 1 == 1). */ append_workers_push_event(f, 700ULL, "workerA"); append_workers_push_event(f, 800ULL, "workerB"); append_replay_session(f, 2000000000ULL); /* round 1: idle */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture(replay_path, "continue\nquit\n", "_svcontsuppressaux"); /* Confirm the suppressed routine events really produced no line at all * -- reusing test_repl_event_echo.c's own Event Echo Gate assertion * pattern so this test's "after a stretch of suppressed routine * events" framing is verified here, not merely assumed. */ TEST_ASSERT_NULL_MESSAGE( strstr(captured, "[sim] event: QUEUE_UPDATE"), "the routine events preceding the structural events must produce " "no line at all under continue mode (scheduler-sim-repl-verbosity " "Requirement 1) -- this test's premise"); build_preamble_line(preambleA, sizeof(preambleA), 700ULL, 1ULL); build_preamble_line(preambleB, sizeof(preambleB), 800ULL, 1ULL); preambleA_pos = strstr(captured, preambleA); preambleB_pos = strstr(captured, preambleB); contentA_pos = strstr(captured, "[sim] event: WORKERS_PUSH nworkers=1 names=[workerA]"); contentB_pos = strstr(captured, "[sim] event: WORKERS_PUSH nworkers=1 names=[workerB]"); TEST_ASSERT_NOT_NULL_MESSAGE( preambleA_pos, "workerA is the first ECHOED event of this continue-mode run (the " "suppressed routine events before it never touched the dedup " "cache) -- it must print its own preamble (Requirement 1.2)"); TEST_ASSERT_NOT_NULL_MESSAGE(contentA_pos, "workerA's content line " "must appear"); TEST_ASSERT_NOT_NULL_MESSAGE(contentB_pos, "workerB's content line " "must appear"); /* THE RED ASSERTION: workerB shares its immediately preceding echoed * event's (workerA's) rendered timestamp and session, so its preamble * must be omitted -- the same rule Test 1 exercises in step mode, * proven here to apply identically under continue mode's structural * echo path (Requirement 1.1). */ TEST_ASSERT_NULL_MESSAGE( preambleB_pos, "workerB shares its immediately preceding ECHOED event's (workerA) " "rendered timestamp and session -- its preamble must be omitted " "(Requirement 1.1); expected to fail against today's REPL"); TEST_ASSERT_TRUE_MESSAGE(preambleA_pos < contentA_pos, "workerA's preamble must precede its own " "content line"); TEST_ASSERT_TRUE_MESSAGE(contentA_pos < contentB_pos, "event content lines must stay in their " "original relative order (Requirement 2.2)"); free(captured); printf( "test_structural_event_after_suppressed_routine_events_follows_" "dedup_rule: PASS\n"); } /* ---------------------------------------------------------------------- */ /* Test 6: an event's own content line and the relative ordering of all */ /* events' content lines are completely unaffected by the preamble dedup */ /* decision, generalized to THREE consecutive same-context events mixing */ /* routine and structural types (Requirements 1.4, 2.2) -- a stronger, */ /* standalone regression guard than Test 1's two-event case, mirroring the */ /* "3 consecutive same-context events" precedent test_repl_breakpoints_ */ /* inspection.c's test_step_echoes_events_before_session_decisions already */ /* establishes (without that test's own jobid-bearing event types, per */ /* this file's job-free discipline). */ /* ---------------------------------------------------------------------- */ static void test_event_content_and_ordering_preserved_regardless_of_preamble_dedup(void) { char replay_path[PATH_MAX]; FILE* f; char* captured; char preamble1[96]; char preamble2[96]; char preamble3[96]; char* content1_pos; char* content2_pos; char* content3_pos; f = write_header_and_snapshot(replay_path, sizeof(replay_path), "_svcontentorder"); TEST_ASSERT_NOT_NULL(f); /* Three consecutive events -- routine, structural, routine -- all * decoded before the first ReplaySession boundary, so all three share * the same displayed session (1) and (all three raw ts values below * floor to second 0) the same rendered timestamp. "step" (STEP mode) * echoes routine events too, so all three are echoed. */ append_queue_update_event(f, 100ULL, "q1"); append_workers_push_event(f, 200ULL, "wA"); append_queue_update_event(f, 300ULL, "q2"); append_replay_session(f, 2000000000ULL); /* round 1: idle */ append_end_of_stream_marker(f); fclose(f); captured = run_repl_fixture_and_capture(replay_path, "step\nquit\n", "_svcontentorderaux"); content1_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=q1"); content2_pos = strstr( captured, "[sim] event: WORKERS_PUSH nworkers=1 names=[wA]"); content3_pos = strstr(captured, "[sim] event: QUEUE_UPDATE queue=q2"); TEST_ASSERT_NOT_NULL_MESSAGE(content1_pos, "q1's content line must " "appear"); TEST_ASSERT_NOT_NULL_MESSAGE(content2_pos, "wA's content line must " "appear"); TEST_ASSERT_NOT_NULL_MESSAGE(content3_pos, "q2's content line must " "appear"); /* THIS TEST'S PRIMARY ASSERTION (Requirement 1.4, 2.2): every event's * own content line stays present, in its original relative order, * regardless of the preamble dedup decision or whether the event type * mixes routine and structural classifications. */ TEST_ASSERT_TRUE_MESSAGE( content1_pos < content2_pos, "q1's content line must precede wA's, unaffected by preamble " "dedup (Requirement 2.2)"); TEST_ASSERT_TRUE_MESSAGE( content2_pos < content3_pos, "wA's content line must precede q2's, unaffected by preamble " "dedup (Requirement 2.2)"); /* Incidental reinforcement of Requirement 1.1 generalizing to N=3 * consecutive same-context events across mixed event types -- not this * test's main purpose (that is the ordering assertion above), but a * natural corollary of the fixture's construction. */ build_preamble_line(preamble1, sizeof(preamble1), 100ULL, 1ULL); build_preamble_line(preamble2, sizeof(preamble2), 200ULL, 1ULL); build_preamble_line(preamble3, sizeof(preamble3), 300ULL, 1ULL); TEST_ASSERT_NOT_NULL_MESSAGE(strstr(captured, preamble1), "q1 (first echo) must print its preamble"); TEST_ASSERT_NULL_MESSAGE( strstr(captured, preamble2), "wA shares q1's rendered context -- its preamble must be omitted " "(Requirement 1.1), expected to fail against today's REPL"); TEST_ASSERT_NULL_MESSAGE( strstr(captured, preamble3), "q2 shares q1's/wA's rendered context -- its preamble must be " "omitted (Requirement 1.1), expected to fail against today's REPL"); free(captured); printf( "test_event_content_and_ordering_preserved_regardless_of_preamble_" "dedup: PASS\n"); } int main(void) { UNITY_BEGIN(); RUN_TEST(test_second_event_with_same_rendered_context_omits_preamble); RUN_TEST(test_events_across_session_boundary_both_print_own_preamble); RUN_TEST(test_dedup_key_is_rendered_timestamp_not_raw_nanoseconds); RUN_TEST(test_first_echoed_event_in_fresh_session_prints_preamble); RUN_TEST( test_structural_event_after_suppressed_routine_events_follows_dedup_rule); RUN_TEST( test_event_content_and_ordering_preserved_regardless_of_preamble_dedup); return UNITY_END(); }