lei.chen/myxce
1
0
Fork 1
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

feat(scheduler-core): implement clock virtualization and session timing (task 4.5)

Browse source 
Adds xce_core_now() (new core_clock.c, kept separate from core.c so
test_core_isolation.c's wall-clock scan still enforces zero direct
clock_gettime()/time() calls elsewhere in the core): the two-anchor
plus speed formula (virtual_clock_base + (elapsed * speed_num) /
speed_den), covering all four modes (normal, discrete/real-time/fast-
slow simulation) via four new atomic fields on xce_sched_core_t,
defaulted to normal-mode (1/1 speed) in xce_sched_core_init().

requirements.md's literal tlog_reg_format_func(fn, core_ptr) call
shape doesn't exist in the real vendored tlog library (registration
takes only the callback; userptr is per-call-site, not bindable at
registration) -- resolved with a module-level active-core pointer read
by a new core-scoped format function, not wired into mylog_init()/
main.c yet. xce_core_go()/xce_core_end_session() (task 4.4) now stamp
session_start/compute session_duration_ns via xce_core_now(), with
their existing session-active/reentrancy behavior untouched.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019dw5WnN3DXStaEaPYfACU1
This commit is contained in:
Rongsong Shen 2026-08-04 03:38:58 +00:00
parent de69b6288d
commit c5432f7786
Signed by: rshen
SSH key fingerprint: SHA256:8Vf2pZ3h6rJa7EhGK+WaAQ9Mta/apZvteW6g9U/WKKk
9 changed files with 849 additions and 5 deletions
Download patch file Download diff file Expand all files Collapse all files

4
.kiro/specs/scheduler-core/tasks.md
View file

@ -115,12 +115,13 @@
- _Depends: 4.3_
- _Verified: 2026-08-03 — xce_core_go()/xce_core_end_session() (new core_session.c) implement the non-blocking session-start signal (-EINVAL on reentrant call, proven a true no-op via cbuf_tryget) and end-session cleanup; xce_core_set_decision_cb() registers the driver's on_decision callback (separate setter, not an xce_sched_core_init() param, to avoid touching its live sched_init() call site); XCE_DECISION_PREEMPT added to decision.h matching the DISPATCH/PEND/PREEMPT AC 6 table exactly. Decision-drain loop confirmed driver-owned (not a core function) via 3 independent requirements.md/design.md citations, re-derived independently by review. Additive only, sched_go/sched_begin_session/sched_end_session/sched_allocator/main.c untouched. REJECTED round 1 on a clang-format alignment regression in core.h (mid-struct insertion de-aligned 24 pre-existing lines) — fixed with clang-format -i, whitespace-only, re-verified 17/17 green._
- [ ] 4.5 Implement clock virtualization and session timing
- [x] 4.5 Implement clock virtualization and session timing
- Implement the virtualized clock accessor using the two-anchor-plus-speed formula, backed by atomically-updated fields; no direct wall-clock call anywhere else in the core
- Register the core's own log-timestamp formatter, bound to the virtualized clock accessor instead of the logging library's default wall-clock read — this is the one third-party dependency inside the core that would otherwise call wall-clock time on every log line, silently reintroducing the exact dependency task 4.1 confirmed absent at link time
- Track session start/end timestamps internally and compute session duration for diagnostics, exposed through the session summary
- Observable: the clock accessor's output matches the documented formula for all four operating modes (normal, discrete simulation, real-time simulation, fast/slow simulation) given fixed anchor values; a log line emitted while the virtual clock is frozen at a fixed simulated timestamp shows that timestamp, not the real wall-clock time at the moment of the call
- _Requirements: 5.3, 5.12_
- _Verified: 2026-08-03 — xce_core_now() (new core_clock.c, kept out of core.c so test_core_isolation.c's wall-clock scan still passes) implements the exact two-anchor+speed formula; all 4 modes proven with fixed anchors, no sleep-based flakiness. requirements.md's literal tlog_reg_format_func(fn, core_ptr) call shape doesn't exist in the real vendored tlog API (verified against tlog.h: registration takes only the callback, userptr is per-call-site) — resolved via a module-level active-core pointer read by a new core-scoped format function, not wired into mylog_init()/main.c yet. session_start/session_duration_ns stamped correctly in xce_core_go()/xce_core_end_session() (task 4.4's behavior otherwise untouched). 18/18 scheduler suite passing, clang-format clean, review APPROVED first pass. Follow-up noted: core_clock.c is the 3rd core-adjacent file (after core_events.c, core_session.c) outside test_core_isolation.c's nm-based audit — manually verified clean, not mechanically enforced._
- _Depends: 4.1_
- [ ] 4.6 Core contract tests
@ -366,3 +367,4 @@
- Two follow-ups surfaced by task 2.4's review, not yet fixed (outside its file boundary): (1) `main.c` discards `sched_init()`'s return value, so a bad `job_pick_plugin` config fails `sched_init()` correctly but the process doesn't yet halt on it — needs a fast follow-up before relying on "fails startup" in production. (2) `pthread_testcancel()` in `builtin_fcfs_next_job()` is only at the loop entry/exit, not scattered through the queue/job walk (the walk holds `fcfs_plugin_data_t.lock` throughout, and this codebase has no `pthread_cleanup_push` precedent to safely unlock on mid-walk cancellation) — behaviorally inert today since `sched_queue_is_ready`/`sched_job_is_ready` are `return 1` stubs, but becomes a real cancellation-latency gap once Phase 2 implements real filtering.
- Task 4.2's Req 5 AC 7 kvmgr iteration-order audit (scope: jobs/queues/users/projects, per design.md's bounded-scope note) found no unstable site — recorded durably as a comment in `core.c` above `xce_sched_core_init()`. One open gap surfaced but explicitly out of this task's scope: `core->workers` is iterated order-sensitively by `sched_collect_workers()` → `seqjob_allocator.c`'s first-fit `sched_try_alloc_on_hosts()`, and design.md itself says the full AC 7 guarantee must close "before Phase 3 simulation work depends on it" — needs a follow-up audit/fix (or an explicit documented exemption) before Phase 3 (tasks 7+) starts relying on scheduling determinism across worker selection.
- Task 4.3 split its implementation into a NEW file `core_events.c` (not `core.c`, which design.md's File Structure Plan literally names) because implementing `xce_core_push_events()` directly in `core.c` would have pushed it to 977 lines, over this project's 800-line hard cap. `core.h` (the public contract) matches design.md's intent; only the `.c` file location differs. Worth reflecting in design.md next time it's touched. Also: `test_core_isolation.c`'s nm(1)-based zero-controller-I/O boundary audit (Req 5 AC 3) covers only `core.c`, not `core_events.c` — manually verified clean (no netio/xceapi/client/delay/idgen usage) but not mechanically enforced; extending that test to cover `core_events.c` would be a reasonable low-risk follow-up before later tasks add more logic to this file.
- Same pattern compounded across tasks 4.4 (`core_session.c`) and 4.5 (`core_clock.c`, which also genuinely NEEDS to be outside the wall-clock-call scan since it's the one file allowed to call `clock_gettime`) — `test_core_isolation.c` now covers only `core.c`, while three sibling files (`core_events.c`/`core_session.c`/`core_clock.c`) sit outside its mechanical audit, each manually verified clean but not enforced by a test. Worth a dedicated follow-up task extending the forbidden-header/forbidden-symbol half of the audit (not the wall-clock half, which `core_clock.c` must stay exempt from) to all `core_*.c` files before Phase 3 adds more.

98
src/scheduler/include/core.h
View file

@ -23,6 +23,19 @@
* testsuite/test_core_isolation.c (source-text scan + an nm(1) undefined-
* symbol audit of core.c's compiled object, the build-time proof this
* task's Observable requires).
*
* One documented exception (task 4.5, Req 5 AC 3): the core's single
* sanctioned wall-clock call -- clock_gettime(CLOCK_MONOTONIC) inside
* xce_core_now() -- and its tlog format-function integration live in
* core_clock.c, a SEPARATE file from core.c, specifically so
* test_core_isolation.c's core.c-scoped "zero wall-clock calls" text scan
* keeps proving what it has always proven (core.c itself never reads real
* time) without needing to special-case the one legitimate call site AC 3
* mandates. tlog (tinylog) is likewise an allowed core dependency as of
* this task -- AC 3's own "Third-party library constraint" section
* discusses the core registering a tlog format function -- distinct from
* the forbidden client.h/netio.h/xceapi.h/delay.h/idgen.h/xce/cluster.h
* list above, none of which tlog is part of.
*/
#include <pthread.h>
@ -102,6 +115,55 @@ struct xce_sched_core_s {
_Atomic int staging_merge_complete; /* 1 after staging merge completes */
select_eval_ctx_t* sel_eval_ctx; /* session-level memoisation context; NULL
between sessions */
/*
* Clock virtualization (Req 5 AC 3, scheduler-core spec, task 4.5): the
* core's ONLY sanctioned time source is xce_core_now() (core_clock.c),
* which computes virtual time from these four fields via the
* two-anchor + speed formula:
*
* wall_ns = clock_gettime(CLOCK_MONOTONIC) // the one wall-clock
* // call in the whole
* // core -- lives in
* // core_clock.c, NOT
* // core.c (core.c's own
* // zero-wall-clock
* // guarantee, enforced
* // by
* // test_core_isolation.c,
* // stays intact)
* elapsed = wall_ns - real_clock_base
* xce_core_now() = virtual_clock_base + (elapsed * speed_num) / speed_den
*
* Atomically updated by the driver AS A GROUP before each event
* dispatch (design.md's State Management note) -- xce_core_now() reads
* them lock-free, no mutex, safe from both the picker and allocator
* threads. xce_sched_core_init() seeds these to AC 3's Normal-mode row
* (virtual_clock_base=0, real_clock_base=0, speed_num=1, speed_den=1):
* degraded-to-real-wall-clock default, today's existing production
* behavior, preserved until a future simulation driver (Phase 3)
* explicitly reconfigures them.
*/
_Atomic uint64_t virtual_clock_base;
_Atomic uint64_t real_clock_base;
_Atomic uint64_t speed_num;
_Atomic uint64_t speed_den;
/*
* Session response-time diagnostics (Req 5 AC 12, task 4.5). Plain
* (non-atomic) fields -- touched only by the driver thread, inside
* xce_core_go()/xce_core_end_session() (core_session.c), the same
* single-writer discipline core->sel_eval_ctx above already follows.
* session_start is stamped at the top of xce_core_go(); the field name
* matches requirements.md's own pseudocode verbatim
* ("session_start = xce_core_now()"). session_duration_ns is computed
* at the top of xce_core_end_session() as xce_core_now() -
* session_start. Both are diagnostics only -- nothing in the
* scheduling/decision path reads them. The ReplaySession.summary
* SessionSummary wire struct these values eventually feed is explicitly
* OUT of this task's scope (Phase 3, recording/replay-format tasks
* 7.x) -- this struct only holds the plain numeric tracking.
*/
uint64_t session_start;
uint64_t session_duration_ns;
};
/*
@ -302,4 +364,40 @@ extern int xce_core_go(xce_sched_core_t*);
*/
extern int xce_core_end_session(xce_sched_core_t*);
/*
* xce_core_now - Req 5 AC 3 (scheduler-core spec, task 4.5): the core's
* virtualized clock accessor, and the ONLY place inside the scheduler-core
* module family that calls clock_gettime() (implemented in core_clock.c,
* deliberately NOT core.c -- see this header's own top-of-file boundary
* comment and xce_sched_core_t's clock-field doc comment above for why).
* Computes virtual time via the two-anchor + speed formula from
* virtual_clock_base/real_clock_base/speed_num/speed_den, reading all four
* atomically (lock-free, safe from any thread). Returns 0 if core is NULL.
*/
extern uint64_t xce_core_now(xce_sched_core_t*);
/*
* xce_core_set_active_for_logging / xce_core_register_tlog_format - Req 5
* AC 3's tlog integration (task 4.5). See core_clock.c's own file header
* comment for the full reasoning behind this exact mechanism, including why
* it deliberately does NOT match AC 3's literal
* `tlog_reg_format_func(fn, core_ptr)` pseudocode -- that call shape does
* not exist in the real vendored tlog.h (`tlog_reg_format_func()` takes
* only the callback, no userptr-binding parameter; userptr is a per-call-
* site argument that flows through tlog_ext()/tlog_vext(), not something
* bindable once at registration time).
*
* xce_core_set_active_for_logging(core) sets (or, passed NULL, clears) a
* module-level "active core for logging" pointer that core_clock.c's
* registered tlog_format_func reads via xce_core_now() instead of
* info->time. xce_core_register_tlog_format() registers that format
* function with tlog via the real tlog_reg_format_func(). Neither is
* called from mylog_init()/main.c by this task -- wiring the live
* scheduler process over to this mechanism is a later task's job,
* consistent with tasks 4.1-4.4's additive-only, unwired-until-a-driver-
* exists pattern.
*/
extern void xce_core_set_active_for_logging(xce_sched_core_t*);
extern int xce_core_register_tlog_format(void);
#endif

1
src/scheduler/meson.build
View file

@ -5,6 +5,7 @@ scheduler_srcs = [
'src/core.c',
'src/core_events.c',
'src/core_session.c',
'src/core_clock.c',
'src/decision.c',
'src/schedobj.c',
'src/plugin.c',

12
src/scheduler/src/core.c
View file

@ -127,6 +127,18 @@ int xce_sched_core_init(xce_sched_core_t* core)
core->nextid = 1;
core->configver = 0;
/* Req 5 AC 3 (scheduler-core spec, task 4.5): seed the clock atoms to
* AC 3's Normal-mode row. virtual_clock_base/real_clock_base are
* already correct from the memset() above (both 0); speed_num/
* speed_den must be set explicitly to 1/1 -- memset() would otherwise
* leave them at 0/1, which is the FROZEN/discrete-simulation row, not
* Normal -- so a freshly initialized core degrades to real wall-clock
* time via xce_core_now() (today's existing production behavior),
* preserved until a future simulation driver (Phase 3) explicitly
* reconfigures these fields as a group. */
atomic_store_explicit(&(core->speed_num), 1, memory_order_release);
atomic_store_explicit(&(core->speed_den), 1, memory_order_release);
xstring_table_init(1024 * 1024);
mylock_init(&(core->lock));

233
src/scheduler/src/core_clock.c Normal file
View file

@ -0,0 +1,233 @@
#include <stdarg.h>
#include <stdatomic.h>
#include <stdio.h>
#include <time.h>
#include <unistd.h>
#include "core.h"
#include "utils.h"
/*
* core_clock.c - clock virtualization and the core's tlog format-function
* integration (scheduler-core spec, task 4.5, Req 5 AC 3). New file (not
* appended to core.c) for one deliberate reason: xce_core_now() must call
* clock_gettime(CLOCK_MONOTONIC) -- AC 3's own pseudocode names this the
* "only wall-clock call in the core" -- and test_core_isolation.c's
* regression guard (task 4.1) does a literal source-text scan of core.c
* for "clock_gettime(" (among other wall-clock substrings) and fails on
* any match, with no exception carve-out. Putting the one sanctioned call
* site in a SEPARATE file keeps that existing, already-passing test
* meaningful (core.c itself is still, and remains, provably wall-clock-
* free) while still giving the core exactly the single documented
* exception AC 3 requires. core.h's own boundary comment records this same
* reasoning for future readers.
*
* Public surface (core.h): xce_core_now(), xce_core_set_active_for_logging(),
* xce_core_register_tlog_format().
*
* --- The tlog_reg_format_func() signature mismatch, and how this file
* --- resolves it (Req 5 AC 3's tlog integration bullet):
*
* requirements.md's own pseudocode reads: "The core shall register its own
* format function via `tlog_reg_format_func(fn, core_ptr)` where `core_ptr`
* is the `xce_sched_core_t*`." That exact call shape does not exist. The
* real vendored tlog.h (tinylog 1.0.0) declares:
*
* typedef int (*tlog_format_func)(char *buff, int maxlen,
* struct tlog_loginfo *info, void *userptr, const char *format,
* va_list ap);
* extern int tlog_reg_format_func(tlog_format_func callback);
*
* -- ONE argument, the callback, full stop. `userptr` is real, but it is a
* PER-CALL-SITE parameter that flows through tlog_ext()/tlog_vext() (every
* ERROR()/WARN()/INFO()/TRACE() macro ultimately calls tlog_ext(..., NULL,
* ...) with a hardcoded NULL userptr -- see utils.h's `tlog(level, format,
* ...)` macro), not something bindable once at registration time.
* src/lib/utils.c's existing my_tlog_format() already receives this same
* userptr parameter today and explicitly ignores it (xce_use(userptr)),
* reading info->time (populated by tlog itself from real wall-clock time)
* instead.
*
* Threading a `core` pointer through as userptr at every one of the
* scheduler's ERROR/WARN/INFO/TRACE call sites (rewriting the tlog(...)
* macro's hardcoded NULL to a real per-file/per-module core pointer,
* scheduler-wide) would be the only way to honor the pseudocode's literal
* userptr-per-call-site shape -- a massive, invasive, out-of-scope change
* this task's boundary does not license (task 4.5 is "clock virtualization
* and session timing", not "rewire every log call site in the scheduler").
*
* The mechanism actually implemented here: a module-level pointer to "the
* core currently active for logging purposes"
* (g_active_core_for_logging), set via xce_core_set_active_for_logging()
* -- a small, core-scoped setter a driver calls once (this task does not
* wire it into mylog_init()/main.c; that remains a later task's job, same
* additive-only pattern as tasks 4.1-4.4). xce_core_tlog_format() -- the
* REAL tlog_format_func registered via xce_core_register_tlog_format() --
* reads g_active_core_for_logging and, when non-NULL, formats
* xce_core_now(that core) instead of info->time. This is the only
* mechanism that actually exists in tlog's real API without a scheduler-
* wide invasive rewrite: `tlog_loginfo`/`info->time` are populated by tlog
* itself, inside tlog_ext(), before any format function ever runs (there is
* no seam to "pre-populate" info->time from the caller's side either --
* tlog_ext()'s implementation, not this file, owns that population).
*/
/* Nanoseconds per second -- named per this project's "no hardcoded values"
* convention; used both by xce_core_now()'s wall-clock read and
* ns_to_tlog_time()'s epoch-seconds/microseconds split below. */
#define CORE_CLOCK_NSEC_PER_SEC 1000000000ULL
uint64_t xce_core_now(xce_sched_core_t* core)
{
struct timespec ts;
uint64_t wall_ns;
uint64_t vbase;
uint64_t rbase;
uint64_t num;
uint64_t den;
uint64_t elapsed;
if (core == NULL) {
return 0;
}
/* The ONE wall-clock call in the entire scheduler-core module family
* (Req 5 AC 3's pseudocode: "only wall-clock call in the core"). See
* this file's own header comment for why it lives here and not
* core.c. */
clock_gettime(CLOCK_MONOTONIC, &ts);
wall_ns = ((uint64_t)ts.tv_sec * CORE_CLOCK_NSEC_PER_SEC)
+ (uint64_t)ts.tv_nsec;
vbase = atomic_load_explicit(&(core->virtual_clock_base),
memory_order_acquire);
rbase
= atomic_load_explicit(&(core->real_clock_base), memory_order_acquire);
num = atomic_load_explicit(&(core->speed_num), memory_order_acquire);
den = atomic_load_explicit(&(core->speed_den), memory_order_acquire);
if (den == 0) {
/* Defensive: AC 3's documented mode table never sets speed_den to
* 0 (discrete-simulation freezes via speed_num=0, not speed_den=0)
* -- this guard only prevents undefined-behavior-by-malformed-
* input, it is never expected to trigger in a correct driver. */
den = 1;
}
elapsed = wall_ns - rbase;
return vbase + (elapsed * num) / den;
}
/*
* g_active_core_for_logging - see this file's header comment for the full
* tlog_reg_format_func() signature-mismatch reasoning. NULL until a driver
* calls xce_core_set_active_for_logging(); xce_core_tlog_format() falls
* back to info->time (tlog's own real-wall-clock read) while NULL,
* matching src/lib/utils.c's default formatter's behavior exactly.
*/
static _Atomic(xce_sched_core_t*) g_active_core_for_logging = NULL;
void xce_core_set_active_for_logging(xce_sched_core_t* core)
{
atomic_store_explicit(&g_active_core_for_logging, core,
memory_order_release);
}
/*
* ns_to_tlog_time - converts a virtualized-clock nanoseconds-since-epoch
* value (xce_core_now()'s return) into struct tlog_time via gmtime_r(), per
* Req 5 AC 3's own text: "converting nanoseconds to struct tm fields via
* gmtime_r() (deterministic -- pure computation)". This is NOT a
* wall-clock read: gmtime_r() performs a pure calendar conversion on a
* value already obtained through xce_core_now() -- no
* time()/clock_gettime()/gettimeofday() call appears here.
*/
static void ns_to_tlog_time(uint64_t ns, struct tlog_time* out)
{
time_t secs = (time_t)(ns / CORE_CLOCK_NSEC_PER_SEC);
struct tm gmt;
gmtime_r(&secs, &gmt);
out->year = gmt.tm_year + 1900;
out->mon = (unsigned char)(gmt.tm_mon + 1);
out->mday = (unsigned char)gmt.tm_mday;
out->hour = (unsigned char)gmt.tm_hour;
out->min = (unsigned char)gmt.tm_min;
out->sec = (unsigned char)gmt.tm_sec;
out->usec = (unsigned int)((ns % CORE_CLOCK_NSEC_PER_SEC) / 1000ULL);
}
/*
* xce_core_tlog_format - Req 5 AC 3's tlog integration point (task 4.5).
* Mirrors src/lib/utils.c's my_tlog_format() prefix layout EXACTLY (same
* two snprintf format strings -- file:line for sub-INFO levels, func name
* otherwise -- same getpid()/level-string fields) with exactly one
* substitution: the timestamp source. Where my_tlog_format() always reads
* info->time (populated by tlog itself from real wall-clock time at the
* log call site), this function reads xce_core_now(g_active_core_for_logging)
* when an active core is registered -- giving every ERROR/WARN/INFO/TRACE
* call site inside the core the virtualized timestamp for free, with zero
* call-site changes. Falls back to info->time when no active core is
* registered (NULL), identical to today's default behavior -- see this
* file's header comment for the full reasoning.
*/
static int xce_core_tlog_format(char* buff, int maxlen,
struct tlog_loginfo* info, void* userptr,
const char* fmt, va_list ap)
{
xce_sched_core_t* core;
struct tlog_time virt_time;
struct tlog_time* tm;
int len;
int total_len = 0;
xce_use(userptr);
core = atomic_load_explicit(&g_active_core_for_logging,
memory_order_acquire);
if (core != NULL) {
ns_to_tlog_time(xce_core_now(core), &virt_time);
tm = &virt_time;
} else {
tm = &(info->time);
}
if (info->level < TLOG_INFO) {
len = snprintf(
buff, maxlen,
"[%.4d-%.2d-%.2d %.2d:%.2d:%.2d,%.3d] [%5d] [%6s] [%17s:%-4d] ",
tm->year, tm->mon, tm->mday, tm->hour, tm->min, tm->sec,
tm->usec / 1000, getpid(), tlog_get_level_string(info->level),
info->file, info->line);
} else {
len = snprintf(
buff, maxlen,
"[%.4d-%.2d-%.2d %.2d:%.2d:%.2d,%.3d] [%5d] [%6s] [%22s] ",
tm->year, tm->mon, tm->mday, tm->hour, tm->min, tm->sec,
tm->usec / 1000, getpid(), tlog_get_level_string(info->level),
info->func);
}
if (len < 0 || len >= maxlen) {
return -1;
}
buff += len;
total_len += len;
maxlen -= len;
/* format log message */
len = vsnprintf(buff, maxlen, fmt, ap);
if (len < 0 || len == maxlen) {
return -1;
}
total_len += len;
return total_len;
}
int xce_core_register_tlog_format(void)
{
return tlog_reg_format_func(xce_core_tlog_format);
}

11
src/scheduler/src/core_session.c
View file

@ -362,6 +362,11 @@ int xce_core_go(xce_sched_core_t* core)
atomic_store_explicit(&(core->session_active), 1, memory_order_release);
/* Req 5 AC 12 (scheduler-core spec, task 4.5): stamp session_start via
* the virtualized clock accessor -- never a direct wall-clock call
* (this file's own boundary comment, above). */
core->session_start = xce_core_now(core);
core_begin_session_internal(core);
/* NON-BLOCKING: wbuf has capacity 1 and is empty between sessions (the
@ -382,6 +387,12 @@ int xce_core_end_session(xce_sched_core_t* core)
core_end_session_internal(core);
/* Req 5 AC 12 (scheduler-core spec, task 4.5): session_duration_ns =
* xce_core_now() - session_start, computed before session_active
* clears (matches core_go()'s ordering: state pertaining to THIS
* session is finalized before the session is marked inactive). */
core->session_duration_ns = xce_core_now(core) - core->session_start;
atomic_store_explicit(&(core->session_active), 0, memory_order_release);
return 0;

20
src/scheduler/testsuite/meson.build
View file

@ -259,6 +259,23 @@ sched_core_session_test = executable(
dependencies: [scheduler_test_deps],
install: false)
# Contract test for clock virtualization and session timing (scheduler-core
# spec, task 4.5, Req 5 AC 3 / AC 12): xce_core_now()'s two-anchor + speed
# formula for all four documented modes, xce_core_tlog_format()'s tlog
# integration (frozen virtual time shown instead of info->time's real
# wall-clock read), and session_start/session_duration_ns tracking across a
# real xce_core_go()/xce_core_end_session() cycle. Same white-box #include
# pattern as test_core_session.c (pulls ../src/core.c, ../src/core_session.c,
# and ../src/decision.c into this TU) PLUS ../src/core_clock.c (this task's
# new file -- see that file's own header comment for why xce_core_now()/
# the tlog format function live there, not in core.c).
sched_core_clock_test = executable(
'sched_core_clock_test',
['test_clock.c'],
include_directories:[incdir],
dependencies: [scheduler_test_deps],
install: false)
# Register as meson tests so `meson test --suite scheduler` runs them all.
# detect_leaks=0 matches the suite convention (fixtures are not torn down).
test('scheduler test', scheduler_test, suite: 'scheduler',
@ -301,3 +318,6 @@ test('scheduler core events test',
test('scheduler core session test',
sched_core_session_test, suite: 'scheduler',
env: ['ASAN_OPTIONS=detect_leaks=0'])
test('scheduler core clock test',
sched_core_clock_test, suite: 'scheduler',
env: ['ASAN_OPTIONS=detect_leaks=0'])

461
src/scheduler/testsuite/test_clock.c Normal file
View file

@ -0,0 +1,461 @@
/*
* 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 <stdarg.h>
#include <stdint.h>
#include <string.h>
#include <time.h>
#include <unity/unity.h>
#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));
}
/* ---------------------------------------------------------------------- */
/* 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_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();
}

14
src/scheduler/testsuite/test_core_session.c
View file

@ -27,11 +27,16 @@
* - xce_core_end_session() clears session_active back to 0, unblocking
* the next xce_core_go() call.
*
* White-box #include of ../src/core.c, ../src/core_session.c, and
* ../src/decision.c (same convention as test_core_events.c/
* test_core_jbuf_capacity_pin.c) so this test exercises the REAL
* xce_sched_core_init()/xce_core_go()/xce_core_end_session()/
* White-box #include of ../src/core.c, ../src/core_session.c,
* ../src/core_clock.c, and ../src/decision.c (same convention as
* test_core_events.c/test_core_jbuf_capacity_pin.c) so this test exercises
* the REAL xce_sched_core_init()/xce_core_go()/xce_core_end_session()/
* xce_core_set_decision_cb()/make_*_decision(), not a re-implementation.
* core_clock.c joined this file's #include list in task 4.5 (scheduler-core
* spec): xce_core_go()/xce_core_end_session() now call xce_core_now()
* (Req 5 AC 12 session timing), which core_clock.c is the only TU that
* defines -- see test_clock.c for that function's own dedicated contract
* tests; this file does not re-test the clock formula itself.
* Unlike test_core_events.c, this file does not need core_events.c or a
* working picker plugin resolution -- xce_core_go()/xce_core_end_session()
* never call sched_resolve_job_picker() (verified: grep confirms neither
@ -54,6 +59,7 @@
* xce_core_end_session()/xce_core_set_decision_cb()/make_*_decision()
* 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"