myxce/src/scheduler/testsuite/test_repl_step_verbosity.c
Rongsong Shen 6a2aa47f5e
test(scheduler-sim-step-verbosity): task 1.1 - RED tests for preamble dedup
Adds 6 failing tests for the Event Echo Preamble Deduplicator
(Requirements 1.1-1.4, 2.2): a second echoed event sharing its
predecessor's rendered timestamp+session omits its preamble; two
events across a session boundary both print their own preamble; the
critical raw-vs-rendered nuance (Requirement 1.3) - two events whose
raw nanosecond timestamps genuinely differ but whose rendered,
second-granularity timestamp and session are identical still dedupe,
with a fixture-premise self-check proving the two raw values really
do render identically; the first echoed event in a fresh session
always prints its preamble; a structural event under continue mode
after suppressed routine events follows the same rule; event content
and ordering are unaffected regardless of the preamble decision.

Lands in a new test_repl_step_verbosity.c (1010 lines, 6 tests) rather
than extending test_repl_event_echo.c (705 lines) - proactive split
per this file family's established practice, since appending would
have pushed that file well past the project's ~1000-line trigger.
Registered in testsuite/meson.build. No production code touched.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01YAWMhfRJFnmmnG8h97yUDd
2026-09-03 03:54:01 +00:00

1010 lines
41 KiB
C

/*
* 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=<ns> (<ISO8601>) session=<N>" 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=<ns> (<ISO8601>)
* session=<N>\n" where <ns> is the exact raw nanosecond value
* xce_core_now() returns for that event (see the determinism note
* above), <ISO8601> is that same value rendered via
* repl_format_ts_human() to second granularity, and <N> 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 <ISO8601> or <N> differs from the
* immediately preceding ECHOED event's own printed <ISO8601>/<N> (or
* when there is no preceding echoed event this session) -- never based
* on the raw <ns> value, which may legitimately differ between two
* events sharing the same displayed <ISO8601>/<N> (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 <errno.h>
#include <limits.h>
#include <stdatomic.h>
#include <stdbool.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/wait.h>
#include <unistd.h>
#include <unity/unity.h>
#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_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; }
/* 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_scheduler_t* sched, xvec_idval_t* vec,
xlist_t* limits)
{
(void)sched;
(void)vec;
(void)limits;
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;
}
/* 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;
}
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
* (<ISO8601>, 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();
}