/* * test_clock.c - contract test for clock virtualization and session timing * (scheduler-core spec, task 4.5, Req 5 AC 3 / AC 12). * * Observable under test: * - xce_core_now() implements the two-anchor + speed formula (Req 5 AC 3) * exactly, for all four documented operating modes (normal, discrete * simulation, real-time simulation, fast/slow simulation), given fixed * anchor values -- no sleep-based real-elapsed-time assertions. Where a * mode's own definition makes the output track real wall-clock time * (normal, real-time, fast/slow), the test brackets the result between * two back-to-back CLOCK_MONOTONIC reads taken immediately before/after * the call -- deterministic (time is monotonic, so the bracket always * holds) and fast (nanoseconds of real work between the two reads), NOT * the sleep-then-check-approximate-elapsed pattern this task forbids. * Discrete-simulation (frozen, speed=0/1) collapses the bracket to an * exact equality since elapsed*0/den is always 0 regardless of when the * test runs. * - xce_core_tlog_format() (core_clock.c's registered tlog_format_func) * reads xce_core_now() of the module-level "active core for logging" * when one is registered, IGNORING info->time (which tlog itself * populates from real wall-clock time at the call site) -- so a log * line formatted while the virtual clock is frozen shows the frozen * simulated timestamp, not real wall-clock time. Falls back to * info->time when no active core is registered (matching today's * default formatter's behavior). * - xce_core_register_tlog_format() really registers with the real * tlog_reg_format_func() (proves xce_core_tlog_format's signature is * genuinely tlog_format_func-compatible -- this file would fail to * compile otherwise -- and that tlog accepts it at runtime). * - session_start is stamped at the top of xce_core_go() and * session_duration_ns is computed at the top of xce_core_end_session() * as xce_core_now() - session_start (Req 5 AC 12), exercised through * the REAL xce_core_go()/xce_core_end_session() (core_session.c) with * the core's clock frozen (discrete-simulation mode) so both the * zero-duration case (AC 12's own "fast mode ... duration_ns is * typically 0" note) and a nonzero case (clock advanced between go() * and end_session(), the same anchor-update-between-events pattern a * real driver follows) are fully deterministic. * * White-box #include of ../src/core_clock.c (xce_core_now(), * xce_core_tlog_format(), g_active_core_for_logging, * xce_core_register_tlog_format() -- same convention as every other * white-box test in this directory) PLUS ../src/core.c, ../src/core_session.c, * and ../src/decision.c (same set test_core_session.c already pulls in) so * the session-timing tests exercise the REAL xce_core_go()/ * xce_core_end_session(), not a re-implementation. The kill_sched_ family, * plugin_unregister, and sched_worker_release_host_ctx stubs below exist * purely to satisfy the linker for xce_sched_core_init()'s * kvmgr_params_t.datakiller fields and core_session.c's core_reset_workers() * -- never actually invoked, same rationale test_core_session.c's own header * comment documents. */ #include #include #include #include #include #include "preason.h" /* Pull in the real xce_core_now()/xce_core_tlog_format()/ * xce_core_register_tlog_format()/xce_sched_core_init()/xce_core_go()/ * xce_core_end_session() under test into this TU (white-box #include). */ #include "../src/core.c" #include "../src/core_clock.c" #include "../src/core_session.c" #include "../src/decision.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; } void plugin_unregister(void* arg) { (void)arg; } void sched_worker_release_host_ctx(xce_sched_worker_t* w) { (void)w; } void setUp(void) { return; } void tearDown(void) { return; } /* ---------------------------------------------------------------------- */ /* Helpers */ /* ---------------------------------------------------------------------- */ #define TEST_NSEC_PER_SEC 1000000000ULL static uint64_t test_monotonic_ns(void) { struct timespec ts; clock_gettime(CLOCK_MONOTONIC, &ts); return ((uint64_t)ts.tv_sec * TEST_NSEC_PER_SEC) + (uint64_t)ts.tv_nsec; } static void set_clock_atoms(xce_sched_core_t* core, uint64_t vbase, uint64_t rbase, uint64_t num, uint64_t den) { atomic_store_explicit(&(core->virtual_clock_base), vbase, memory_order_release); atomic_store_explicit(&(core->real_clock_base), rbase, memory_order_release); atomic_store_explicit(&(core->speed_num), num, memory_order_release); atomic_store_explicit(&(core->speed_den), den, memory_order_release); } static void fixture_init(xce_sched_core_t* core) { int rc = xce_sched_core_init(core); TEST_ASSERT_EQUAL_INT(0, rc); } /* ---------------------------------------------------------------------- */ /* xce_core_now() -- two-anchor + speed formula (Req 5 AC 3) */ /* ---------------------------------------------------------------------- */ static void test_xce_core_now_null_core_returns_zero(void) { TEST_ASSERT_EQUAL_UINT64(0, xce_core_now(NULL)); } static void test_xce_core_now_normal_mode_matches_wall_clock(void) { /* Normal mode (AC 3's table): virtual_clock_base=0, real_clock_base=0, * speed=1/1 -- degraded to real wall clock: 0 + (wall-0)*1/1 = wall. */ xce_sched_core_t core; uint64_t before, result, after; memset(&core, 0, sizeof(core)); set_clock_atoms(&core, 0, 0, 1, 1); before = test_monotonic_ns(); result = xce_core_now(&core); after = test_monotonic_ns(); TEST_ASSERT_TRUE(result >= before); TEST_ASSERT_TRUE(result <= after); } static void test_xce_core_now_discrete_simulation_frozen_at_event_ts(void) { /* Simulation discrete (AC 3's table): virtual_clock_base=event ts, * real_clock_base=wall at load, speed=0/1 -- frozen at ts regardless of * real elapsed time (elapsed * 0 / 1 == 0 always). Exact equality, no * bracket needed -- the whole point of this mode. */ xce_sched_core_t core; const uint64_t EVENT_TS = 1700000000123456789ULL; uint64_t result; memset(&core, 0, sizeof(core)); set_clock_atoms(&core, EVENT_TS, test_monotonic_ns(), 0, 1); result = xce_core_now(&core); TEST_ASSERT_EQUAL_UINT64(EVENT_TS, result); /* Re-reading later still returns the identical frozen value -- proves * "time does not advance between events", not a one-shot coincidence. */ result = xce_core_now(&core); TEST_ASSERT_EQUAL_UINT64(EVENT_TS, result); } static void test_xce_core_now_realtime_simulation_tracks_wall_clock_from_anchor(void) { /* Simulation real-time (AC 3's table): virtual_clock_base=snapshot ts, * real_clock_base=wall at load, speed=1/1 -- tracks wall clock from the * virtual anchor: result is between [snapshot_ts, snapshot_ts + * (after-before)]. */ xce_sched_core_t core; const uint64_t SNAPSHOT_TS = 500000000000ULL; uint64_t before, result, after; memset(&core, 0, sizeof(core)); before = test_monotonic_ns(); set_clock_atoms(&core, SNAPSHOT_TS, before, 1, 1); result = xce_core_now(&core); after = test_monotonic_ns(); TEST_ASSERT_TRUE(result >= SNAPSHOT_TS); TEST_ASSERT_TRUE(result <= SNAPSHOT_TS + (after - before)); } static void test_xce_core_now_fast_simulation_scales_up_by_speed(void) { /* Simulation fast (AC 3's table): speed=N/1 -- runs N times faster than * wall clock. Bracket scaled by N. */ xce_sched_core_t core; const uint64_t SNAPSHOT_TS = 1000ULL; const uint64_t N = 1000ULL; uint64_t before, result, after; memset(&core, 0, sizeof(core)); before = test_monotonic_ns(); set_clock_atoms(&core, SNAPSHOT_TS, before, N, 1); result = xce_core_now(&core); after = test_monotonic_ns(); TEST_ASSERT_TRUE(result >= SNAPSHOT_TS); TEST_ASSERT_TRUE(result <= SNAPSHOT_TS + (after - before) * N); } static void test_xce_core_now_slow_simulation_scales_down_by_speed(void) { /* Simulation slow (AC 3's table): speed=1/N -- runs N times slower than * wall clock. Bracket scaled down by N (+1 for integer-division * rounding slack). */ xce_sched_core_t core; const uint64_t SNAPSHOT_TS = 1000ULL; const uint64_t N = 1000ULL; uint64_t before, result, after; memset(&core, 0, sizeof(core)); before = test_monotonic_ns(); set_clock_atoms(&core, SNAPSHOT_TS, before, 1, N); result = xce_core_now(&core); after = test_monotonic_ns(); TEST_ASSERT_TRUE(result >= SNAPSHOT_TS); TEST_ASSERT_TRUE(result <= SNAPSHOT_TS + (after - before) / N + 1); } /* ---------------------------------------------------------------------- */ /* Clock virtualization is atomically updated as a group (Req 5 AC 3) */ /* ---------------------------------------------------------------------- */ static void test_xce_sched_core_init_seeds_normal_mode_defaults(void) { /* xce_sched_core_init() (core.c, task 4.5) must seed the clock atoms * to AC 3's Normal-mode row -- preserving today's real-wall-clock * default until a simulation driver reconfigures them. */ xce_sched_core_t core; fixture_init(&core); TEST_ASSERT_EQUAL_UINT64(0, atomic_load_explicit(&(core.virtual_clock_base), memory_order_acquire)); TEST_ASSERT_EQUAL_UINT64( 0, atomic_load_explicit(&(core.real_clock_base), memory_order_acquire)); TEST_ASSERT_EQUAL_UINT64( 1, atomic_load_explicit(&(core.speed_num), memory_order_acquire)); TEST_ASSERT_EQUAL_UINT64( 1, atomic_load_explicit(&(core.speed_den), memory_order_acquire)); } /* ---------------------------------------------------------------------- */ /* xce_core_set_wallclock_anchor() -- normal-mode epoch seeding (bug-1584) */ /* ---------------------------------------------------------------------- */ static uint64_t test_epoch_ns(void) { struct timespec ts; clock_gettime(CLOCK_REALTIME, &ts); return ((uint64_t)ts.tv_sec * TEST_NSEC_PER_SEC) + (uint64_t)ts.tv_nsec; } static void test_xce_core_set_wallclock_anchor_seeds_real_epoch_time(void) { /* bug-1584: xce_sched_core_init() alone leaves xce_core_now() returning * raw CLOCK_MONOTONIC-since-boot nanoseconds (see * test_xce_sched_core_init_seeds_normal_mode_defaults above) -- NOT * epoch time, which every real consumer of a normal-mode timestamp * needs (recording.c's record_start_ts, SchedAdminReply.startedAt, * documented in controller.capnp as "nanoseconds since epoch"). * xce_core_set_wallclock_anchor() is the fix: bracket its effect on * xce_core_now() between two back-to-back CLOCK_REALTIME reads taken * immediately before/after the call -- deterministic (real time only * moves forward) and immune to sleep-based flakiness. Before this fix, * `result` would be a small monotonic-since-boot value, far below * `before` (a real epoch value ~1.7e18 ns as of 2026) -- this bracket * fails loudly on that regression rather than passing by coincidence. */ xce_sched_core_t core; uint64_t before, result, after; fixture_init(&core); before = test_epoch_ns(); xce_core_set_wallclock_anchor(&core); result = xce_core_now(&core); after = test_epoch_ns(); TEST_ASSERT_TRUE(result >= before); TEST_ASSERT_TRUE(result <= after); } static void test_xce_core_set_wallclock_anchor_null_core_is_a_safe_noop(void) { /* Mirrors xce_core_now(NULL)'s defensive contract -- no crash. */ xce_core_set_wallclock_anchor(NULL); } /* ---------------------------------------------------------------------- */ /* tlog format integration (Req 5 AC 3) */ /* ---------------------------------------------------------------------- */ static int call_format(char* buff, int maxlen, struct tlog_loginfo* info, void* userptr, const char* fmt, ...) { va_list ap; int rc; va_start(ap, fmt); rc = xce_core_tlog_format(buff, maxlen, info, userptr, fmt, ap); va_end(ap); return rc; } static void test_tlog_format_shows_frozen_virtual_time_not_infotime(void) { /* Freeze the active core's virtual clock at a known simulated instant * (2033-05-18 03:04:05 UTC) and set info->time to a deliberately * DIFFERENT, real-looking wall-clock value (1999-01-01) -- proving the * formatter reads the frozen simulated time, not info->time. */ xce_sched_core_t core; struct tlog_loginfo info; char buff[256]; int rc; const uint64_t FROZEN_NS = 2000000000ULL * TEST_NSEC_PER_SEC; /* 2033-05-18ish -- exact date not asserted; only that it is NOT the * info->time value below. */ memset(&core, 0, sizeof(core)); set_clock_atoms(&core, FROZEN_NS, test_monotonic_ns(), 0, 1); memset(&info, 0, sizeof(info)); info.level = TLOG_INFO; info.file = "test.c"; info.func = "test_func"; info.line = 42; info.time.year = 1999; info.time.mon = 1; info.time.mday = 1; info.time.hour = 0; info.time.min = 0; info.time.sec = 0; info.time.usec = 0; xce_core_set_active_for_logging(&core); rc = call_format(buff, sizeof(buff), &info, NULL, "hello %d", 7); TEST_ASSERT_TRUE(rc > 0); TEST_ASSERT_NOT_NULL(strstr(buff, "hello 7")); TEST_ASSERT_NULL_MESSAGE( strstr(buff, "1999"), "formatted log line must NOT show info->time's wall-clock year " "while the virtual clock is frozen"); xce_core_set_active_for_logging(NULL); } static void test_tlog_format_frozen_time_is_stable_across_calls(void) { /* Formatting twice, with no change to the frozen anchors, must produce * an IDENTICAL timestamp both times -- the direct proof that the shown * timestamp is the frozen simulated ts, not whatever the real clock * happens to read at each call. */ xce_sched_core_t core; struct tlog_loginfo info; char buff1[256]; char buff2[256]; char* ts_end1; char* ts_end2; const uint64_t FROZEN_NS = 1234567890ULL * TEST_NSEC_PER_SEC; memset(&core, 0, sizeof(core)); set_clock_atoms(&core, FROZEN_NS, test_monotonic_ns(), 0, 1); memset(&info, 0, sizeof(info)); info.level = TLOG_INFO; info.func = "test_func"; xce_core_set_active_for_logging(&core); call_format(buff1, sizeof(buff1), &info, NULL, "first"); call_format(buff2, sizeof(buff2), &info, NULL, "second"); xce_core_set_active_for_logging(NULL); /* Both lines share the same "[YYYY-MM-DD HH:MM:SS,mmm]" prefix -- find * the closing bracket of the timestamp portion and compare up to it. */ ts_end1 = strchr(buff1, ']'); ts_end2 = strchr(buff2, ']'); TEST_ASSERT_NOT_NULL(ts_end1); TEST_ASSERT_NOT_NULL(ts_end2); TEST_ASSERT_EQUAL_INT(ts_end1 - buff1, ts_end2 - buff2); TEST_ASSERT_TRUE(strncmp(buff1, buff2, (size_t)(ts_end1 - buff1)) == 0); } static void test_tlog_format_falls_back_to_infotime_when_no_active_core(void) { /* No active core registered (NULL, the module's own default) -- * xce_core_tlog_format() must fall back to info->time, matching * src/lib/utils.c's my_tlog_format() default behavior exactly. */ struct tlog_loginfo info; char buff[256]; int rc; xce_core_set_active_for_logging(NULL); memset(&info, 0, sizeof(info)); info.level = TLOG_INFO; info.func = "test_func"; info.time.year = 2077; info.time.mon = 6; info.time.mday = 15; info.time.hour = 12; info.time.min = 30; info.time.sec = 45; info.time.usec = 0; rc = call_format(buff, sizeof(buff), &info, NULL, "fallback"); TEST_ASSERT_TRUE(rc > 0); TEST_ASSERT_NOT_NULL(strstr(buff, "2077-06-15")); } static void test_xce_core_register_tlog_format_succeeds(void) { int rc = xce_core_register_tlog_format(); TEST_ASSERT_EQUAL_INT(0, rc); } /* ---------------------------------------------------------------------- */ /* Session timing (Req 5 AC 12) */ /* ---------------------------------------------------------------------- */ static void test_session_duration_zero_when_clock_frozen_across_session(void) { /* AC 12's own note: "in fast mode the virtual clock freezes during * core_go() so duration_ns is typically 0". Discrete-simulation mode * (speed=0/1) reproduces exactly that: xce_core_now() returns the same * frozen value at both core_go() and core_end_session(). */ xce_sched_core_t core; int rc; int go = 0; const uint64_t FROZEN_TS = 42424242ULL; fixture_init(&core); set_clock_atoms(&core, FROZEN_TS, test_monotonic_ns(), 0, 1); rc = xce_core_go(&core); TEST_ASSERT_EQUAL_INT(0, rc); TEST_ASSERT_EQUAL_UINT64(FROZEN_TS, core.session_start); cbuf_tryget(&(core.wbuf), &go); /* drain the signal, not under test here */ rc = xce_core_end_session(&core); TEST_ASSERT_EQUAL_INT(0, rc); TEST_ASSERT_EQUAL_UINT64(0, core.session_duration_ns); } static void test_session_duration_reflects_clock_advance_between_go_and_end(void) { /* Models a real driver updating the clock atoms between events (AC 3: * "the driver atomically updates all four fields before each event * dispatch") -- the virtual clock advances by a known, fixed amount * between core_go() and core_end_session(), fully deterministic (no * sleep, no real elapsed time involved). */ xce_sched_core_t core; int rc; int go = 0; const uint64_t START_TS = 1000000ULL; const uint64_t ADVANCE = 250000ULL; fixture_init(&core); set_clock_atoms(&core, START_TS, test_monotonic_ns(), 0, 1); rc = xce_core_go(&core); TEST_ASSERT_EQUAL_INT(0, rc); TEST_ASSERT_EQUAL_UINT64(START_TS, core.session_start); cbuf_tryget(&(core.wbuf), &go); /* Driver advances virtual_clock_base before the next dispatch -- still * frozen (speed 0/1) at the new value, so end_session() sees exactly * START_TS + ADVANCE, deterministically. */ atomic_store_explicit(&(core.virtual_clock_base), START_TS + ADVANCE, memory_order_release); rc = xce_core_end_session(&core); TEST_ASSERT_EQUAL_INT(0, rc); TEST_ASSERT_EQUAL_UINT64(ADVANCE, core.session_duration_ns); } int main(void) { UNITY_BEGIN(); RUN_TEST(test_xce_core_now_null_core_returns_zero); RUN_TEST(test_xce_core_now_normal_mode_matches_wall_clock); RUN_TEST(test_xce_core_now_discrete_simulation_frozen_at_event_ts); RUN_TEST( test_xce_core_now_realtime_simulation_tracks_wall_clock_from_anchor); RUN_TEST(test_xce_core_now_fast_simulation_scales_up_by_speed); RUN_TEST(test_xce_core_now_slow_simulation_scales_down_by_speed); RUN_TEST(test_xce_sched_core_init_seeds_normal_mode_defaults); RUN_TEST(test_xce_core_set_wallclock_anchor_seeds_real_epoch_time); RUN_TEST(test_xce_core_set_wallclock_anchor_null_core_is_a_safe_noop); RUN_TEST(test_tlog_format_shows_frozen_virtual_time_not_infotime); RUN_TEST(test_tlog_format_frozen_time_is_stable_across_calls); RUN_TEST(test_tlog_format_falls_back_to_infotime_when_no_active_core); RUN_TEST(test_xce_core_register_tlog_format_succeeds); RUN_TEST(test_session_duration_zero_when_clock_frozen_across_session); RUN_TEST(test_session_duration_reflects_clock_advance_between_go_and_end); return UNITY_END(); }