diff --git a/.wolf/memory.md b/.wolf/memory.md index c7c24706..0c0d1504 100644 --- a/.wolf/memory.md +++ b/.wolf/memory.md @@ -2520,3 +2520,39 @@ | 21:10 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 23 reads | ~127583 tok | | 21:11 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 23 reads | ~127583 tok | | 21:12 | Fixed StartTime/FinishTime never set (raft-apply-decoupling apply-pump gap) — wal_type-keyed time(NULL) stamping in apply_committed_entry, TDD RED->GREEN, bug-1561 re-observed (6th time, unrelated overlayfs artifact, not a regression) | src/controller/persist.c, src/controller/testsuite/test_apply_committed_entry.c, .wolf/buglog.json | GREEN, 1107 Tests 2 pre-existing-unrelated Failures | ~35000 | +| 21:25 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 23 reads | ~127583 tok | +| 23:48 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 23 reads | ~127583 tok | +| 06:49 | Rebuilt scheduler debug profile (src/build.dbg) via xce-build.sh to deploy bug-1600 fix (group.c makeGroup rtti free) for pc13v crash-loop; ran meson test --suite scheduler | src/build.dbg/scheduler/xce_scheduler | build OK, 42 Ok / 1 Fail (bug-1560 pre-existing, unrelated) | ~15000 | +| 23:50 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 24 reads | ~127583 tok | +| 23:58 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 24 reads | ~127583 tok | +| 00:00 | Session end: 9 writes across 4 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c) | 24 reads | ~127583 tok | +| 00:02 | Created .kiro/specs/build-time-versioning/spec.json | — | ~130 | +| 00:02 | Created .kiro/specs/build-time-versioning/requirements.md | — | ~361 | +| 00:04 | Created .kiro/specs/build-time-versioning/requirements.md | — | ~1792 | +| 00:04 | Edited .kiro/specs/build-time-versioning/spec.json | 8→8 lines | ~55 | +| 00:06 | Session end: 13 writes across 6 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c, spec.json) | 36 reads | ~143885 tok | +| 00:18 | Edited src/scheduler/src/repl_info.c | added 3 condition(s) | ~839 | +| 00:18 | Edited src/scheduler/src/repl_info.c | pool() → index() | ~311 | +| 00:18 | Edited src/scheduler/src/repl_info.c | 15→18 lines | ~300 | +| 00:19 | Edited src/scheduler/src/repl_info.c | added 2 condition(s) | ~800 | +| 00:20 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 8→9 lines | ~151 | +| 00:20 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 2→3 lines | ~46 | +| 00:20 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 2→2 lines | ~36 | +| 00:22 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | modified requirement() | ~687 | +| 00:22 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | modified requirement() | ~719 | +| 00:23 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 4→6 lines | ~105 | +| 07:27 | Fixed info resource/info worker to gate value+used display on XCE_RESF_CONSUMABLE, added ordtype to resource definition | src/scheduler/src/repl_info.c, src/scheduler/testsuite/test_repl_breakpoints_inspection.c, .wolf/buglog.json | GREEN, 42/43 Ok, only pre-existing bug-1560 remains | ~90000 | +| 00:29 | Edited src/scheduler/src/repl_break.c | modified 5() | ~460 | +| 00:29 | Edited src/scheduler/src/repl_break.c | inline fix | ~11 | +| 00:30 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | expanded (+19 lines) | ~511 | +| 00:33 | Session end: 26 writes across 9 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c, spec.json) | 52 reads | ~204795 tok | +| 00:36 | Edited src/scheduler/src/repl_break.c | 10→13 lines | ~230 | +| 00:36 | Edited src/scheduler/src/repl_break.c | 3→3 lines | ~53 | +| 00:39 | Edited src/scheduler/src/sim.c | added 7 condition(s) | ~845 | +| 00:39 | Edited src/scheduler/src/sim.c | added 1 condition(s) | ~230 | +| 00:42 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | modified requirement() | ~458 | +| 00:42 | Edited src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 3→4 lines | ~40 | +| 00:43 | Session end: 32 writes across 10 files (test_group.c, group.c, test_apply_committed_entry.c, persist.c, spec.json) | 55 reads | ~220167 tok | +| 07:46 | ASAN build+full testsuite verified for repl_break.c/sim.c session-count changes | src/scheduler/src/repl_break.c, src/scheduler/src/sim.c, src/scheduler/testsuite/test_repl_breakpoints_inspection.c | 42/43 Ok, only known bug-1560 admin_request symlink failure; new+changed tests all PASS | ~55k | +| 00:48 | Created ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-scheduler-framework/0334ebbe-8d9c-4931-871d-87c678f83a79/scratchpad/log_bug_1602.py | — | ~1054 | +| 08:31 | Added event time/session echo (session_count+1, events precede their own BEGIN_ROUND marker) and replay-file session-count pre-scan (ftell/fseek, shape-only) | src/scheduler/src/repl_break.c, src/scheduler/src/sim.c, src/scheduler/testsuite/test_repl_breakpoints_inspection.c, .wolf/buglog.json | GREEN, 42/43 Ok, only pre-existing bug-1560 remains | ~110000 | diff --git a/src/scheduler/src/repl_break.c b/src/scheduler/src/repl_break.c index 9575d9a1..92742701 100644 --- a/src/scheduler/src/repl_break.c +++ b/src/scheduler/src/repl_break.c @@ -569,10 +569,31 @@ bool repl_cmd_delete(xce_sched_sim_driver_t* sim, const char* line) * sim_loop.c), leaving every input event silent unless a breakpoint * happened to match it. Only ever called from xce_repl_on_event() below, * itself only reached when sim->interactive (repl.h's own gate) -- zero - * output added to batch `--sim` mode. + * output added to batch `--sim` mode. Prefixed with a "[sim] t=... (...) + * session=..." line (same xce_core_now()/repl_format_ts_human()/ + * rs->session_count sources `info session`/`info config`, repl_info.c, + * already use) so an operator reading a step/continue transcript can tell + * WHEN each event happened and which session it belongs to, not just what + * happened. Uses session_count+1, NOT the raw count: sim_loop.c's replay + * reader calls xce_repl_check_event() (-> here) for every raw event AS IT + * STREAMS IN, and only reads that batch's own ReplaySession/begin_round + * message (which is what increments session_count, xce_repl_on_begin_round) + * AFTER all of that session's events -- file order is event, event, ..., + * ReplaySession. So every event echoed here always belongs to the session + * about to begin, never one already counted. */ -static void repl_print_event_summary(const xce_core_event_t* ev) +static void repl_print_event_summary(xce_sched_sim_driver_t* sim, + const xce_core_event_t* ev) { + xce_sched_repl_state_t* rs = sim->repl_state; + char ts_human[32]; + + repl_format_ts_human(xce_core_now(&(sim->core)), ts_human, + sizeof(ts_human)); + fprintf(stdout, "[sim] t=%llu (%s) session=%llu\n", + (unsigned long long)xce_core_now(&(sim->core)), ts_human, + (unsigned long long)((rs != NULL) ? rs->session_count + 1 : 1)); + switch (ev->type) { case XCE_CORE_EVENT_CONFIG_PUSH: fprintf(stdout, "[sim] event: CONFIG_PUSH\n"); @@ -699,7 +720,7 @@ void xce_repl_on_event(xce_sched_sim_driver_t* sim, xce_core_event_t* ev) /* task 12.5, bug-1595: unconditional echo, printed before the * breakpoint check below so the operator sees "event happened" before * (if it also matches) "breakpoint hit". */ - repl_print_event_summary(ev); + repl_print_event_summary(sim, ev); bp = repl_find_event_breakpoint(rs, ev); if (bp != NULL) { diff --git a/src/scheduler/src/sim.c b/src/scheduler/src/sim.c index 3e3ae6ca..9ef56d53 100644 --- a/src/scheduler/src/sim.c +++ b/src/scheduler/src/sim.c @@ -327,6 +327,87 @@ static void sim_set_virtual_clock(xce_sched_sim_driver_t* sim, sim->sim_speed_den = 1; } +/* + * sim_prescan_session_count - counts the total number of ReplaySession + * (BEGIN_ROUND) messages remaining in sim->replay_file from the current + * position onward, then rewinds the file back to that exact position, so + * sched_sim_driver_start() can report "this replay file has N sessions" up + * front, before sched_sim_driver_run()'s real event loop (sim_loop.c) + * starts consuming the same stream. Uses the identical shape-only + * classification (msg_root_has_shape()) sim_loop.c's own main loop uses to + * tell ReplayEvent/ReplaySession/SnapshotEntry messages apart, and the same + * ftell()/fseek() rewind technique sim_locate_and_load_snapshot() above + * already establishes -- safe because this codebase's capn_init_fp() calls + * are always unpacked (packed=0), which reads via a single plain fread() + * per message with no internal read-ahead buffer (msg_root_has_shape()'s + * own file header comment), so ftell()/fseek() stay exactly in sync with + * message boundaries. Never decodes a message's fields, only its wire + * shape -- counting needs nothing more. Scope: only sim->replay_file's own + * session count is reported -- a run under --sim-alt-events substitutes a + * DIFFERENT event stream at run time (sim_loop.c), which this scan does + * not see; a niche enough case that reporting the primary file's own count + * is still the right default. + */ +static int sim_prescan_session_count(xce_sched_sim_driver_t* sim, + uint64_t* out_count) +{ + FILE* f; + long resume_at; + uint64_t count = 0; + + if ((sim == NULL) || (sim->replay_file == NULL) || (out_count == NULL)) { + return -EINVAL; + } + + f = sim->replay_file; + resume_at = ftell(f); + if (resume_at < 0) { + return -errno; + } + + for (;;) { + struct capn c; + capn_ptr root; + + if (capn_init_fp(&c, f, 0) != 0) { + break; /* end of file (or malformed trailing data) -- same + * "nonzero means no more messages" convention every + * other reader in this file follows. */ + } + + if (msg_root_has_shape(&c, &root, ReplaySession_word_count, + ReplaySession_pointer_count)) { + count++; + capn_free(&c); + continue; + } + + if (msg_root_has_shape(&c, &root, ReplayEvent_word_count, + ReplayEvent_pointer_count)) { + capn_free(&c); + continue; + } + + if (msg_root_has_shape(&c, &root, SnapshotEntry_word_count, + SnapshotEntry_pointer_count)) { + capn_free(&c); /* mid-replay checkpoint -- skip, don't stop */ + continue; + } + + /* Unrecognized shape -- end of the message stream, same stop + * condition sim_loop.c's own main loop uses. */ + capn_free(&c); + break; + } + + if (fseek(f, resume_at, SEEK_SET) != 0) { + return -errno; + } + + *out_count = count; + return 0; +} + int sched_sim_driver_start(xce_sched_sim_driver_t* sim, const sched_sim_args_t* args) { @@ -393,6 +474,22 @@ int sched_sim_driver_start(xce_sched_sim_driver_t* sim, sim_set_virtual_clock(sim, snapshot_ts, args->sim_speed); + /* Orientation for an operator about to `step`/`continue` through this + * file (or watch a batch --sim run go by): how many sessions are there + * in total? Purely informational -- a scan failure (e.g. a stat error + * on an already-open, already-validated file) is not fatal to starting + * the simulation, so it is silently skipped rather than aborting + * startup over a diagnostic nicety. */ + { + uint64_t total_sessions = 0; + + if (sim_prescan_session_count(sim, &total_sessions) == 0) { + fprintf(stdout, "[sim] replay file contains %llu session%s\n", + (unsigned long long)total_sessions, + (total_sessions == 1) ? "" : "s"); + } + } + /* Req 5 AC 3 (design review follow-up, 2026-08-19): activate the * virtualized clock for tlog logging now that it's seeded -- every * ERROR/WARN/INFO/TRACE line emitted for the rest of this run shows diff --git a/src/scheduler/testsuite/test_repl_breakpoints_inspection.c b/src/scheduler/testsuite/test_repl_breakpoints_inspection.c index e37619ce..f9c182aa 100644 --- a/src/scheduler/testsuite/test_repl_breakpoints_inspection.c +++ b/src/scheduler/testsuite/test_repl_breakpoints_inspection.c @@ -1779,11 +1779,74 @@ static void test_step_echoes_events_before_session_decisions(void) "events must be echoed BEFORE the session's " "resulting decision (bug-1595)"); + { + char* ts_line_pos = strstr(captured, "[sim] t="); + + TEST_ASSERT_NOT_NULL_MESSAGE( + ts_line_pos, + "each echoed event must be preceded by a t=.../session=... " + "line so an operator can tell when/which session it happened " + "in"); + TEST_ASSERT_TRUE_MESSAGE( + ts_line_pos < jobpush_pos, + "the t=.../session=... line must precede the event it " + "describes"); + TEST_ASSERT_NOT_NULL_MESSAGE( + strstr(captured, "session=1"), + "the first (and only) session's events must be tagged " + "session=1 -- xce_repl_on_begin_round() increments " + "session_count before this session's event batch is pushed"); + } + free(captured); printf("test_step_echoes_events_before_session_decisions: PASS\n"); } +/* + * New requirement (2026-08-20): loading a replay file reports its total + * session count up front (sim.c's sched_sim_driver_start(), via + * sim_prescan_session_count()'s ftell/fseek pre-scan), so an operator knows + * how many `step`s exist before starting to walk through them. + */ +static void test_replay_load_reports_total_session_count(void) +{ + char replay_path[PATH_MAX]; + char aux_dir[PATH_MAX]; + char script_path[PATH_MAX]; + char capture_path[PATH_MAX]; + FILE* f; + char* captured; + + f = write_header_and_snapshot(replay_path, sizeof(replay_path), + "_sessioncount"); + TEST_ASSERT_NOT_NULL(f); + + append_jobs_push_event(f, 1000ULL, 8181ULL, "normal"); + append_replay_session(f, 1500ULL); + append_jobs_push_event(f, 2000ULL, 8182ULL, "normal"); + append_replay_session(f, 2500ULL); + append_end_of_stream_marker(f); + fclose(f); + + make_tmp_dir(aux_dir, sizeof(aux_dir), "_sessioncountaux"); + 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, "quit\n"); + + captured = run_group_d_and_capture(replay_path, script_path, + capture_path); + + TEST_ASSERT_NOT_NULL_MESSAGE( + strstr(captured, "[sim] replay file contains 2 sessions"), + "loading a 2-session replay file must report the total session " + "count up front, before any step/continue command runs"); + + free(captured); + + printf("test_replay_load_reports_total_session_count: PASS\n"); +} + int main(void) { UNITY_BEGIN(); @@ -1818,6 +1881,7 @@ int main(void) RUN_TEST(test_event_breakpoint_pauses_repl_at_matching_event); RUN_TEST(test_decision_breakpoint_pauses_after_decision_output); RUN_TEST(test_step_echoes_events_before_session_decisions); + RUN_TEST(test_replay_load_reports_total_session_count); return UNITY_END(); }