diff --git a/Cargo.toml b/Cargo.toml index 7b828eb908..5956ad1d2a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -44,6 +44,35 @@ opt-level = 0 debug = "line-tables-only" split-debuginfo = "unpacked" +# mimalloc is the `#[global_allocator]` of every native binary in `crates/phase-ai/ +# src/bin/` — the motivating pair is `ai_gate.rs` / `ai_perf_gate.rs`, but all of them +# pick this up. Its entire C core is one unity translation unit +# (`libmimalloc-sys-*/c_src/mimalloc/v3/src/static.c`) and inherits `profile.dev`'s +# `opt-level = 0`, so every allocation in a debug gate run walks an unoptimized malloc. +# Measured on the linked artifact: +# readelf --debug-dump=info target/debug/ai-gate | grep -A1 'GNU C23' +# reported `-O0` for exactly that file before this override and `-O2` after it. +# This is NOT a no-op on the gates' payloads, and the honest statement of why is worth +# more than a clean claim. The AI reads the wall clock on its live decision path: +# `phase-ai/src/projection.rs:110` is `TIME_CAP = 15ms` and `:139-142` bails on it, and +# unlike `search.rs`'s and `planner/mod.rs`'s deadlines it is NOT gated on measurement +# mode. It is reachable at the gate's default `AiDifficulty::Medium` — registry.rs +# registers `EvasionRemovalPriorityPolicy` unconditionally, and its `velocity_score` +# calls `AiSession::get_or_project` → `project_to`, with the `projection_min_budget_ms` +# guard bypassed because a measurement-mode `Deadline` reports no remaining budget to +# compare against. A bail scores 0.0 where a completed projection scores up to +3.0, and +# that term picks the removal target. So making allocation faster lets more projections +# finish, which can change a target, a board, a winner and every counter downstream. +# That hazard is pre-existing and profile-wide (it fires on any faster or slower host); +# this override does not create it and cannot avoid it. It is recorded here because the +# obvious "allocator changes are invisible" claim is false, and the fix — gating +# `TIME_CAP` on measurement mode the way `search.rs:2012` does — belongs in its own +# change with its own baseline sign-off. `RandomState` (#4878) is a separate, +# already-documented source and is seeded from OS randomness, not allocation addresses. +# Scoped to the one package so nothing else loses debug fidelity. +[profile.dev.package.libmimalloc-sys] +opt-level = 2 + [profile.test] inherits = "dev" codegen-units = 256 diff --git a/crates/phase-ai/src/duel_suite/perf.rs b/crates/phase-ai/src/duel_suite/perf.rs index cce8414dbf..d6622473a8 100644 --- a/crates/phase-ai/src/duel_suite/perf.rs +++ b/crates/phase-ai/src/duel_suite/perf.rs @@ -325,13 +325,35 @@ pub fn run_perf_suite( ) -> PerfReport { let start = Instant::now(); let mut counters = PerfCounters::default(); - for id in scenarios { + for (n, id) in scenarios.iter().enumerate() { let spec = find_matchup(id) .unwrap_or_else(|| panic!("perf scenario id '{id}' does not resolve via find_matchup")); let (payload, _p0, _p1) = resolve_matchup(db, spec) .unwrap_or_else(|err| panic!("perf scenario '{id}' failed to resolve decks: {err}")); + // Progress goes to STDERR only: the parent gate runs its children with + // `Stdio::null()` on stdout precisely so its own markdown table stays clean + // (`bin/ai_perf_gate.rs:185`), and stderr is inherited so these lines reach + // the CI log. Without them a killed sample leaves no evidence at all — the + // report is written once, after every scenario has finished. + let scenario_start = Instant::now(); + eprintln!( + "perf scenario {n}/{total} '{id}' start (seed={seed} action_cap={action_cap})", + n = n + 1, + total = scenarios.len(), + ); let snapshot = run_perf_scenario(&payload, seed, action_cap); - counters.merge_add(&PerfCounters::from_snapshot(&snapshot)); + let scenario_counters = PerfCounters::from_snapshot(&snapshot); + // One JSON line per scenario: a killed child still leaves a machine-readable + // partial payload for every scenario that did finish. + eprintln!( + "perf scenario {n}/{total} '{id}' done {ms}ms counters={json}", + n = n + 1, + total = scenarios.len(), + ms = scenario_start.elapsed().as_millis(), + json = serde_json::to_string(&scenario_counters) + .unwrap_or_else(|e| format!("")), + ); + counters.merge_add(&scenario_counters); } let wall_clock_ms = start.elapsed().as_millis(); diff --git a/crates/phase-ai/src/duel_suite/run.rs b/crates/phase-ai/src/duel_suite/run.rs index e54a813a9f..e3de8690f7 100644 --- a/crates/phase-ai/src/duel_suite/run.rs +++ b/crates/phase-ai/src/duel_suite/run.rs @@ -1,9 +1,11 @@ //! Suite runner — executes every registered `MatchupSpec` and emits a //! structured JSON report. //! -//! Deterministic-core results are a pure function of `(binary, spec, seed)`. -//! Wall-clock fields are retained in `SuiteReport` for operator visibility but -//! are excluded from [`SuiteReport::deterministic_core`]. +//! Deterministic-core results are a function of `(binary, spec, seed)` **modulo +//! the run-to-run caveats catalogued at the top of [`super::perf`]** — do not read +//! this as byte-stability across repeated runs. Wall-clock fields are retained in +//! `SuiteReport` for operator visibility but are excluded from +//! [`SuiteReport::deterministic_core`]. use std::collections::{HashMap, HashSet}; use std::io::BufWriter; @@ -311,31 +313,106 @@ fn run_all_matchups( return results; } - run_matchups_parallel(db, options, &selected) + run_games_parallel(db, options, &selected) +} + +/// Flat `(selection position, game index)` work list for the game-level runner. +/// +/// A matchup whose decks failed to resolve contributes **no** tasks: it already +/// has a `failed_result`, and enqueuing games for it would run `drive_game` on a +/// payload that does not exist. Positions stay aligned with `payloads`/`selected` +/// so a task can recover its spec, payload and matchup seed by index alone. +fn game_tasks( + payloads: &[Result], + games_per_matchup: usize, +) -> Vec<(usize, usize)> { + payloads + .iter() + .enumerate() + .filter(|(_, payload)| payload.is_ok()) + .flat_map(|(pos, _)| (0..games_per_matchup).map(move |game| (pos, game))) + .collect() +} + +/// Regroup finished games by matchup position, restoring `game_idx` order and +/// summing per-matchup duration. +/// +/// The sort is load-bearing, not cosmetic: `MatchupResult::games` is a field of +/// [`DeterministicSuiteReport`], so games arriving in completion order instead of +/// `game_idx` order would be a real baseline diff on every parallel run. +fn regroup_games( + matchup_count: usize, + mut collected: Vec<(usize, usize, GameResult, u128)>, +) -> Vec<(Vec, u128)> { + // `(pos, game_idx)` pairs are unique, so `game_idx` alone would also be correct + // once the bucketing below splits by `pos`. Keying on both is self-documenting: + // it says the output order is "matchup, then game", which is what the report is. + collected.sort_by_key(|(pos, game_idx, _, _)| (*pos, *game_idx)); + let mut per_matchup: Vec<(Vec, u128)> = + (0..matchup_count).map(|_| (Vec::new(), 0)).collect(); + for (pos, _, game, elapsed_ms) in collected { + let entry = &mut per_matchup[pos]; + entry.0.push(game); + entry.1 += elapsed_ms; + } + per_matchup } /// Run the selected matchups across all available cores via a work-stealing -/// atomic cursor (matchups vary widely in length, so a static split would leave -/// cores idle). Each matchup is a pure function of `(db, spec, options, -/// matchup_seed)` with its seed derived from the original index, so results are -/// byte-identical to a sequential run regardless of scheduling — only live -/// progress order varies. The returned Vec is restored to selection order. -fn run_matchups_parallel( +/// atomic cursor over **(matchup, game) pairs**. +/// +/// The unit of work is one game, not one matchup. Capping the cursor at the +/// matchup count left every core past the third idle on the quick gate +/// (`ai_gate.rs`'s `DEFAULT_QUICK_FILTER` selects three matchups) while the +/// ten games inside each matchup ran strictly one after another. A game is a +/// function of `(payload, seed, difficulty, action_cap)` **modulo #4878** — see +/// [`drive_game`] and the run-to-run caveat at the top of `duel_suite::perf` — +/// and its seed is `base_seed + matchup_idx*1000 + game_idx`, derived from the +/// matchup's ORIGINAL index, so no game's result depends on which worker picked +/// it up or when. Only live progress order varies. +/// +/// Results are regrouped by matchup and re-sorted by `game_idx` before +/// aggregation, so this runner adds no *new* scheduling dependence to +/// `SuiteReport::deterministic_core`. That core is not byte-stable across repeat +/// runs and never was: `RandomState` is seeded per thread from OS randomness and +/// that iteration order reaches AI tie-breaking (#4878). The verdict is +/// insulated from it because `compare::paired_seed_shift` keys on `seed`, not on +/// position. +/// +/// Output contract (changed by this restructuring): per-GAME lines stream live +/// from [`play_reported_game`], interleaved across matchups and each tagged with +/// its matchup id; the per-matchup verdict rows are printed after the join, in +/// selection order. A killed run therefore still leaves every completed game's +/// seed, winner, turn count and duration in the log. +fn run_games_parallel( db: &CardDatabase, options: &SuiteOptions, selected: &[(usize, &MatchupSpec)], ) -> Vec { use std::sync::atomic::{AtomicUsize, Ordering}; - let run_total = selected.len(); + // Payloads are resolved ONCE per matchup, on this thread, before the fan-out: + // deck resolution is pure setup, and re-resolving it per game would add real + // work that the sequential runner never did. A matchup whose decks fail to + // resolve contributes no game tasks and keeps its `failed_result` — one bad + // deck list must not abort the other matchups. + let mut payloads: Vec> = Vec::with_capacity(selected.len()); + for (_, spec) in selected { + payloads.push(build_payload(db, spec)); + } + + let tasks = game_tasks(&payloads, options.games_per_matchup); + let task_total = tasks.len(); let n_workers = std::thread::available_parallelism() .map(|n| n.get()) .unwrap_or(1) - .min(run_total.max(1)); + .min(task_total.max(1)); let cursor = AtomicUsize::new(0); - let done = AtomicUsize::new(0); - let mut collected: Vec<(usize, MatchupResult)> = std::thread::scope(|scope| { + let collected: Vec<(usize, usize, GameResult, u128)> = std::thread::scope(|scope| { + let payloads = &payloads; + let tasks = &tasks; + let cursor = &cursor; let handles: Vec<_> = (0..n_workers) .map(|_| { // The plan-mandated `cargo ai-gate --difficulty hard` runs in a @@ -346,26 +423,30 @@ fn run_matchups_parallel( // production impact. std::thread::Builder::new() .stack_size(32 << 20) - .spawn_scoped(scope, || { - let mut local: Vec<(usize, MatchupResult)> = Vec::new(); + .spawn_scoped(scope, move || { + let mut local: Vec<(usize, usize, GameResult, u128)> = Vec::new(); loop { - let pos = cursor.fetch_add(1, Ordering::Relaxed); - if pos >= run_total { + let next = cursor.fetch_add(1, Ordering::Relaxed); + if next >= task_total { break; } + let (pos, game_idx) = tasks[next]; let (idx, spec) = selected[pos]; + let payload = payloads[pos] + .as_ref() + .expect("only Ok payloads produce game tasks"); let matchup_seed = options.base_seed.wrapping_add(idx as u64 * 1_000); // Parallel path never harvests (harvesting forces the // sequential branch in `run_all_matchups`). - let result = run_single_matchup(db, spec, options, matchup_seed, None); - let completed = done.fetch_add(1, Ordering::Relaxed) + 1; - eprintln!( - "[{completed:>2}/{run_total}] {id} done (games: {games})", - id = spec.id, - games = options.games_per_matchup, + let (game, elapsed_ms) = play_reported_game( + spec, + payload, + options, + matchup_seed, + game_idx, + None, ); - print_matchup_row(&result); - local.push((pos, result)); + local.push((pos, game_idx, game, elapsed_ms)); } local }) @@ -378,10 +459,32 @@ fn run_matchups_parallel( .collect() }); - // Parallel completion is unordered; restore the original selection order so - // the report and any baseline comparison are stable across runs. - collected.sort_by_key(|(pos, _)| *pos); - collected.into_iter().map(|(_, result)| result).collect() + let per_matchup = regroup_games(selected.len(), collected); + + let results: Vec = selected + .iter() + .zip(payloads.iter()) + .zip(per_matchup) + .map( + |(((_, spec), payload), (games, total_duration_ms))| match payload { + Err(reason) => failed_result(spec, reason), + Ok(_) => assemble_matchup_result(spec, options, games, total_duration_ms), + }, + ) + .collect(); + + let run_total = results.len(); + for (n, result) in results.iter().enumerate() { + eprintln!( + "[{n:>2}/{run_total}] {id} done (games: {games})", + n = n + 1, + id = result.matchup_id, + games = options.games_per_matchup, + ); + print_matchup_row(result); + } + + results } fn finalize_report( @@ -408,73 +511,146 @@ fn finalize_report( Ok(report) } -fn run_single_matchup( - db: &CardDatabase, +/// Wall-clock `HH:MM:SS` in UTC for progress lines. +/// +/// The suite has no date dependency (`phase-ai/Cargo.toml` pulls neither `chrono` +/// nor `time`), and a bare elapsed counter is useless once a CI job is killed — +/// the operator needs to line the last emitted game up against the job's own +/// timeline. Seconds-of-day arithmetic is enough for that and cannot drift. +/// Diagnostics only: never parsed, never compared, never part of a verdict. +fn utc_hms() -> String { + let secs = SystemTime::now() + .duration_since(UNIX_EPOCH) + .map(|d| d.as_secs()) + .unwrap_or(0) + % 86_400; + format!( + "{:02}:{:02}:{:02}", + secs / 3600, + (secs % 3600) / 60, + secs % 60 + ) +} + +/// Progress-line label for a finished game's winner. `None` is a draw *or* an +/// aborted game — [`play_reported_game`] prints a distinct `aborted:` line on the +/// panic path, so the two stay distinguishable in a killed run's tail. +fn winner_label(winner: Option) -> &'static str { + match winner { + Some(PlayerId(0)) => "p0", + Some(_) => "p1", + None => "draw", + } +} + +/// Play one suite game and report it. **Sole authority** for what a single game +/// is: the seed derivation, the panic guard, the harvest side-channel and the +/// progress lines all live here, so the sequential runner and the parallel +/// game-level runner cannot drift in `(seed, winner, turns)`. +/// +/// The returned `GameResult` is derived from `(payload, matchup_seed, game_idx, +/// difficulty)` alone: no wall clock this function reads (`Instant::now` for +/// `elapsed_ms`, `utc_hms` for the progress lines) enters it, and neither does +/// completion order or worker index. It is NOT thread-identity-free in the +/// absolute sense — +/// `RandomState` is seeded per thread and leaks into AI tie-breaking (#4878, +/// documented at the top of `duel_suite::perf`) — but that exposure is identical +/// under the sequential and the parallel runner. `elapsed_ms` is the only value +/// this function itself makes scheduling-dependent, and it is excluded from +/// [`SuiteReport::deterministic_core`]. +fn play_reported_game( spec: &MatchupSpec, + payload: &DeckPayload, options: &SuiteOptions, matchup_seed: u64, - mut harvest_sink: Option<&mut HarvestSink>, -) -> MatchupResult { - let payload = match build_payload(db, spec) { - Ok(p) => p, - Err(reason) => return failed_result(spec, &reason), + game_idx: usize, + harvest_sink: Option<&mut HarvestSink>, +) -> (GameResult, u128) { + let seed = matchup_seed.wrapping_add(game_idx as u64); + let start = Instant::now(); + eprintln!( + "{ts} [{id}] game {n}/{total} seed={seed} start", + ts = utc_hms(), + id = spec.id, + n = game_idx + 1, + total = options.games_per_matchup, + ); + let (winner, turns) = if harvest_sink.is_some() { + // Harvester declared OUTSIDE catch_unwind. The observe closure's `&mut` + // borrow ends when the closure returns; `finish(winner)` then runs + // unconditionally (panic → `catch_unwind` Err → winner None → empty + // records, partial buffer dropped with the harvester). + let mut harvester = harvest::GameHarvester::new(seed, spec.id.to_string(), game_idx); + let outcome = std::panic::catch_unwind(AssertUnwindSafe(|| { + run_game_observed(payload, seed, options.difficulty, &mut |state, session| { + harvester.observe(state, session) + }) + })); + let (winner, turns) = match outcome { + Ok(result) => result, + Err(_) => { + eprintln!(" seed {seed} aborted: AI panic during suite game"); + (None, 0) + } + }; + let records = harvester.finish(winner); + if let Some(sink) = harvest_sink { + if let Err(e) = sink.write_records(&records) { + eprintln!(" seed {seed}: harvest write failed: {e}"); + } + } + (winner, turns) + } else { + match std::panic::catch_unwind(AssertUnwindSafe(|| { + run_game(payload, seed, options.difficulty) + })) { + Ok(result) => result, + Err(_) => { + eprintln!(" seed {seed} aborted: AI panic during suite game"); + (None, 0) + } + } }; + let elapsed_ms = start.elapsed().as_millis(); + eprintln!( + "{ts} [{id}] game {n}/{total} seed={seed} done winner={winner} turns={turns} {elapsed_ms}ms", + ts = utc_hms(), + id = spec.id, + n = game_idx + 1, + total = options.games_per_matchup, + winner = winner_label(winner), + ); + ( + GameResult { + seed, + winner: winner.map(|p| p.0), + turns, + }, + elapsed_ms, + ) +} +/// Fold a matchup's finished games into its [`MatchupResult`]. **Sole authority** +/// for the win/draw tally and the [`classify`] verdict, shared by both runners. +/// +/// `games` MUST already be in `game_idx` order — the parallel runner sorts them +/// back before calling. The report field `games` is part of +/// [`SuiteReport::deterministic_core`], so any other order would be a visible +/// baseline diff, not a cosmetic one. +fn assemble_matchup_result( + spec: &MatchupSpec, + options: &SuiteOptions, + games: Vec, + total_duration_ms: u128, +) -> MatchupResult { let mut p0_wins = 0usize; let mut p1_wins = 0usize; let mut draws = 0usize; - let mut games = Vec::with_capacity(options.games_per_matchup); let mut total_turns: u64 = 0; - let mut total_duration_ms: u128 = 0; - - for game_idx in 0..options.games_per_matchup { - let seed = matchup_seed.wrapping_add(game_idx as u64); - let start = Instant::now(); - let (winner, turns) = if harvest_sink.is_some() { - // Harvester declared OUTSIDE catch_unwind. The observe closure's `&mut` - // borrow ends when the closure returns; `finish(winner)` then runs - // unconditionally (panic → `catch_unwind` Err → winner None → empty - // records, partial buffer dropped with the harvester). - let mut harvester = harvest::GameHarvester::new(seed, spec.id.to_string(), game_idx); - let outcome = std::panic::catch_unwind(AssertUnwindSafe(|| { - run_game_observed(&payload, seed, options.difficulty, &mut |state, session| { - harvester.observe(state, session) - }) - })); - let (winner, turns) = match outcome { - Ok(result) => result, - Err(_) => { - eprintln!(" seed {seed} aborted: AI panic during suite game"); - (None, 0) - } - }; - let records = harvester.finish(winner); - if let Some(sink) = harvest_sink.as_deref_mut() { - if let Err(e) = sink.write_records(&records) { - eprintln!(" seed {seed}: harvest write failed: {e}"); - } - } - (winner, turns) - } else { - match std::panic::catch_unwind(AssertUnwindSafe(|| { - run_game(&payload, seed, options.difficulty) - })) { - Ok(result) => result, - Err(_) => { - eprintln!(" seed {seed} aborted: AI panic during suite game"); - (None, 0) - } - } - }; - total_duration_ms += start.elapsed().as_millis(); - total_turns += turns as u64; - games.push(GameResult { - seed, - winner: winner.map(|p| p.0), - turns, - }); - match winner { - Some(PlayerId(0)) => p0_wins += 1, + for game in &games { + total_turns += game.turns as u64; + match game.winner { + Some(0) => p0_wins += 1, Some(_) => p1_wins += 1, None => draws += 1, } @@ -505,6 +681,36 @@ fn run_single_matchup( } } +fn run_single_matchup( + db: &CardDatabase, + spec: &MatchupSpec, + options: &SuiteOptions, + matchup_seed: u64, + mut harvest_sink: Option<&mut HarvestSink>, +) -> MatchupResult { + let payload = match build_payload(db, spec) { + Ok(p) => p, + Err(reason) => return failed_result(spec, &reason), + }; + + let mut games = Vec::with_capacity(options.games_per_matchup); + let mut total_duration_ms: u128 = 0; + for game_idx in 0..options.games_per_matchup { + let (game, elapsed_ms) = play_reported_game( + spec, + &payload, + options, + matchup_seed, + game_idx, + harvest_sink.as_deref_mut(), + ); + total_duration_ms += elapsed_ms; + games.push(game); + } + + assemble_matchup_result(spec, options, games, total_duration_ms) +} + fn build_payload(db: &CardDatabase, spec: &MatchupSpec) -> Result { let p0 = resolve_deck_ref(&spec.p0).map_err(|e| format!("p0 load: {e}"))?; let p1 = resolve_deck_ref(&spec.p1).map_err(|e| format!("p1 load: {e}"))?; @@ -628,9 +834,14 @@ fn run_game_observed( /// actions have been taken (checked at `run_ai_actions` batch boundaries, so the /// realized count may overshoot the cap within a batch — identical semantics to /// the historical `run_game` body, which capped at `MAX_TOTAL_ACTIONS`). The -/// result `(winner, turn_number)` is a pure function of -/// `(binary, payload, seed, difficulty, action_cap)`; no wall-clock or thread -/// scheduling influences it. +/// result `(winner, turn_number)` is a function of +/// `(binary, payload, seed, difficulty, action_cap)` and nothing this function +/// itself reads — but it is NOT wall-clock-free further down. `projection.rs`'s +/// `TIME_CAP` (`projection.rs:110`, 15 ms) is not gated on measurement mode and is +/// reached at `AiDifficulty::Medium` through `EvasionRemovalPriorityPolicy`'s +/// `velocity_score`, so a faster or slower host can change which creature the AI +/// targets. See the run-to-run caveats at the top of [`super::perf`]; this is a +/// second source alongside #4878. pub(crate) fn drive_game( payload: &DeckPayload, seed: u64, @@ -895,6 +1106,129 @@ mod tests { assert!(reason.unwrap().contains("Wilson 95% CI")); } + fn game(seed: u64, winner: Option, turns: u32) -> GameResult { + GameResult { + seed, + winner, + turns, + } + } + + /// A matchup whose decks failed to resolve must enqueue ZERO games — it + /// already carries a `failed_result`, and its `payloads` slot holds no + /// `DeckPayload` for a worker to run. + /// + /// Discriminating: dropping the `payload.is_ok()` filter makes position 1 + /// appear in the output and the `expect("only Ok payloads produce game + /// tasks")` in the worker becomes reachable. Verified by deleting the + /// filter — the equality below then sees the extra `(1, 0)`/`(1, 1)` pair. + #[test] + fn game_tasks_skip_matchups_whose_payload_failed() { + let payloads = vec![ + Ok(DeckPayload::default()), + Err("p0 load: no such deck".to_string()), + Ok(DeckPayload::default()), + ]; + + let tasks = game_tasks(&payloads, 2); + + assert_eq!(tasks, vec![(0, 0), (0, 1), (2, 0), (2, 1)]); + } + + /// Every matchup's games must land in `game_idx` order no matter what order + /// the workers finished them in. `MatchupResult::games` is a + /// `deterministic_core` field, so completion order leaking into it would be a + /// baseline diff on every parallel run. + /// + /// Discriminating by construction: the input is deliberately shuffled + /// (matchup 0's games arrive 2,0,1 and are interleaved with matchup 1's), so + /// removing `regroup_games`' `sort_by_key` yields `[2,0,1]` and the first + /// assertion fails. Verified by deleting the sort. + #[test] + fn regroup_games_restores_game_index_order_from_shuffled_completion() { + let collected = vec![ + (0, 2, game(102, Some(1), 12), 30), + (1, 1, game(1101, None, 21), 100), + (0, 0, game(100, Some(0), 10), 10), + (1, 0, game(1100, Some(0), 20), 200), + (0, 1, game(101, Some(0), 11), 20), + ]; + + let per_matchup = regroup_games(2, collected); + + assert_eq!( + per_matchup[0].0, + vec![ + game(100, Some(0), 10), + game(101, Some(0), 11), + game(102, Some(1), 12) + ], + ); + assert_eq!( + per_matchup[1].0, + vec![game(1100, Some(0), 20), game(1101, None, 21)], + ); + // Durations are summed per matchup, not mixed between them. + assert_eq!(per_matchup[0].1, 60); + assert_eq!(per_matchup[1].1, 300); + } + + /// A matchup that produced no games at all (its payload failed) must still + /// get an empty slot rather than shifting later matchups' games onto it. + #[test] + fn regroup_games_keeps_an_empty_slot_for_a_matchup_with_no_games() { + let collected = vec![(2, 0, game(2100, Some(0), 7), 5)]; + + let per_matchup = regroup_games(3, collected); + + assert!(per_matchup[0].0.is_empty()); + assert!(per_matchup[1].0.is_empty()); + assert_eq!(per_matchup[2].0, vec![game(2100, Some(0), 7)]); + } + + /// `assemble_matchup_result` is the sole authority for BOTH halves of a + /// matchup row: the win/draw tally (read off the games vector) and the + /// [`classify`] verdict plus the two averages (divided by + /// `options.games_per_matchup`, NOT by `games.len()`). + /// + /// The 4-games-against-`games_per_matchup: 16` mismatch is deliberate — it is + /// what makes the denominator observable. Every one of the three uses flips + /// if it is switched to `games.len()`: `avg_turns` 1.625 → 6.5, + /// `avg_duration_ms` 25.0 → 100.0, and the verdict PASS-vs-FAIL, because the + /// Wilson 95% interval for 2/16 excludes 0.50 while the interval for 2/4 + /// (which is centred on 0.50) cannot. A real run always has + /// `games.len() == games_per_matchup`, so the two are indistinguishable there. + #[test] + fn assemble_matchup_result_tallies_from_games_and_divides_by_games_per_matchup() { + let spec = crate::duel_suite::find_matchup("red-mirror").expect("red-mirror must resolve"); + let options = SuiteOptions::new(AiDifficulty::Medium, 16, 7); + let games = vec![ + game(7, Some(0), 5), + game(8, Some(1), 6), + game(9, None, 7), + game(10, Some(0), 8), + ]; + + let result = assemble_matchup_result(spec, &options, games.clone(), 400); + + assert_eq!((result.p0_wins, result.p1_wins, result.draws), (2, 1, 1)); + assert_eq!(result.total_turns, 26); + assert_eq!(result.games, games); + assert_eq!(result.total_duration_ms, 400); + // Denominator is `games_per_matchup` (16), not `games.len()` (4). + assert_eq!(result.avg_turns, 1.625); + assert_eq!(result.avg_duration_ms, 25.0); + assert_eq!(result.status, SuiteStatus::Fail); + assert!( + result + .fail_reason + .as_deref() + .is_some_and(|reason| reason.contains("mirror imbalance")), + "classify must be fed games_per_matchup; got {:?}", + result.fail_reason, + ); + } + /// Observer seam is inert: for the same `(payload, seed)`, a no-op observer /// yields an identical `(winner, turns)` to the un-observed driver. Uses an /// empty `DeckPayload` (both libraries empty → deterministic draw-from-empty diff --git a/crates/phase-ai/src/search.rs b/crates/phase-ai/src/search.rs index 8d6002d9be..a014079a74 100644 --- a/crates/phase-ai/src/search.rs +++ b/crates/phase-ai/src/search.rs @@ -862,9 +862,16 @@ pub fn emit_trace_for_candidate( /// pending-cast branch here means that authority has a gap: the AI entered a /// cast it cannot complete. Fix the gate, not the recovery. /// -/// In release builds we still emit `CancelCast` to keep the match running, but -/// debug builds panic so the gap surfaces during testing instead of silently -/// degrading AI play into cast/cancel churn. +/// Reaching it is REPORTED, not asserted: the branch emits `CancelCast` and a +/// `tracing::error!` in every profile. A `debug_assert!(false, …)` used to live +/// there, which made the two profiles disagree about the game *result* — both AI +/// gates run the dev profile (`.cargo/config.toml`: `ai-gate = "run --bin +/// ai-gate --"`), `duel_suite::run`'s per-game `catch_unwind` scored the panic +/// `(None, 0)`, and the committed win-rate baseline is generated by +/// `scripts/ai-gate.sh`, which builds `--release`. Same code, different verdict, +/// depending on the profile. The gap it guarded is still a real bug — grep the +/// error event, don't reintroduce the panic. +/// /// Deadlock-safe escape hatch when tactical scoring cannot produce an action. /// The WASM bridge exposes this for client AI-controller escape — callers must /// not invent actions from legal-action enumeration order (#6393). @@ -918,16 +925,26 @@ pub fn fallback_action(state: &GameState, config: &AiConfig) -> Option", |obj| obj.name.as_str()); - debug_assert!( - false, - "AI fallback reached during pending cast (variant {variant}, spell {spell}) — \ - can_cast_object_now has a gap that allowed an uncompletable cast through. \ - Tighten the pre-cast check rather than relying on CancelCast recovery." - ); + // Reported, never asserted. This branch is a HANDLED condition: the + // recovery below (CancelCast, CR 601.2) is the correct behavior and is + // what every release build has always done. A `debug_assert!(false, …)` + // here made the two profiles disagree about the *game result*, not just + // about diagnostics: both AI gates run the dev profile + // (`.cargo/config.toml`: `ai-gate = "run --bin ai-gate --"`, no profile + // flag), the panic unwound into `duel_suite::run`'s per-game + // `catch_unwind`, and that seed was scored `(None, 0)` — a DRAW that + // release would have played out. The committed `suite-baseline.json` is + // release-generated (`scripts/refresh-ai-baseline.sh` → `scripts/ai-gate.sh`, + // `cargo build --release`) and contains no such artifact (checked: zero + // `turns == 0` games), so this removal makes the CI run agree with the + // baseline's own profile rather than the other way round. The diagnostic + // value is preserved verbatim in the error event below. tracing::error!( variant, spell, - "AI fallback cancelled an uncompletable cast — can_cast_object_now gap" + "AI fallback cancelled an uncompletable cast — can_cast_object_now has a gap \ + that allowed an uncompletable cast through. Tighten the pre-cast check rather \ + than relying on CancelCast recovery." ); return Some(GameAction::CancelCast); } diff --git a/crates/phase-ai/tests/scenarios.rs b/crates/phase-ai/tests/scenarios.rs index 849a271852..e1341e0af3 100644 --- a/crates/phase-ai/tests/scenarios.rs +++ b/crates/phase-ai/tests/scenarios.rs @@ -1002,9 +1002,24 @@ fn claws_of_gix_def() -> engine::types::ability::AbilityDefinition { } /// V3 (∃-success): board with 4 artifacts (Mox + 3 others) so sacrificing one -/// leaves 3 → Metalcraft holds → a witness exists. Driving the AI loop must -/// COMPLETE without reaching the `fallback_action` panic. The original dead-end -/// would panic here. +/// leaves 3 → Metalcraft holds → a witness exists. +/// +/// **What this test actually pins, measured — the doc it replaces was wrong.** The +/// activation is legal here (the `activation_legal_for` precondition below), and +/// the AI then *declines* it: driving the loop on this board yields exactly +/// `[PassPriority]`. So the load-bearing assertion is the precondition — it fails +/// the moment a Metalcraft/cost regression stops `legal_actions` surfacing the +/// activation. The `assert_no_fallback_cancel` that follows is a guard, not the +/// subject: a board the AI passes on cannot dead-end. The sibling mana-first test +/// is the one that exercises the completion path end to end (measured: +/// `[ActivateAbility, SelectCards, PassPriority]`), and it carries the positive +/// assertion. +/// +/// That the AI declines a legal, witnessed Claws activation is a real observation +/// and is out of scope here; it is disclosed in the commit that added this doc +/// rather than silently papered over. Before the profile-independence fix, this +/// branch also carried a `debug_assert!(false, …)`, which is why the old doc spoke +/// of a panic; no profile panics now. #[test] fn scenario_claws_of_gix_witness_board_does_not_dead_end() { let mut scenario = GameScenario::new(); @@ -1018,11 +1033,12 @@ fn scenario_claws_of_gix_witness_board_does_not_dead_end() { let mut a = scenario.add_creature(P0, &format!("Artifact {i}"), 0, 1); a.as_artifact(); } - { + let claws = { let mut claws = scenario.add_creature(P0, "Claws of Gix", 0, 1); claws.as_artifact(); claws.with_ability_definition(claws_of_gix_def()); - } + claws.id() + }; let mut runner = scenario.build(); { @@ -1033,12 +1049,20 @@ fn scenario_claws_of_gix_witness_board_does_not_dead_end() { state.waiting_for = WaitingFor::Priority { player: P0 }; } + // Precondition, not decoration: `assert_no_fallback_cancel` is a purely + // negative assertion, so without this an unrelated break in the activation's + // legality (Metalcraft comparator, cost payability) would stop the AI ever + // entering a pending cast and leave the test GREEN while the scenario it + // names had stopped happening. The mana-first sibling has the same guard. + assert!( + activation_legal_for(runner.state(), claws), + "witness board must surface the Claws activation before the loop runs" + ); + let ai_players = HashSet::from([P0]); let ai_configs = HashMap::from([(P0, create_config(AiDifficulty::VeryHard, Platform::Native))]); let mut ai_rng = SmallRng::seed_from_u64(19024); let ai_session = phase_ai::session::AiSession::arc_from_game(runner.state()); - // The assertion is non-panic: a recurrence of the dead-end aborts via the - // `fallback_action` debug_assert before this returns. let results = run_ai_actions( runner.state_mut(), &ai_players, @@ -1046,9 +1070,59 @@ fn scenario_claws_of_gix_witness_board_does_not_dead_end() { &mut ai_rng, &ai_session, ); + assert_no_fallback_cancel( + &results, + "witness board must not escape the Claws activation through the fallback", + ); +} + +/// Dead-end detector for the Claws scenarios, working in BOTH profiles. +/// +/// These tests used to detect a recurrence via the `debug_assert!(false, …)` that +/// lived in `search::fallback_action`'s pending-cast branch (their own comments +/// said so), backed by `assert!(results.len() <= 200)`. That length assertion is +/// **structurally vacuous**: `run_ai_actions` is hard-capped at +/// `MAX_AI_ACTIONS_PER_SEQUENCE = 200` (`crates/phase-ai/src/auto_play.rs:20`), so +/// `<= 200` holds for every possible run and cannot fail on its subject. +/// +/// `CancelCast` is rejected from the strategic pool (`tactical_gate.rs:205`, +/// `GameAction::CancelCast => GateDecision::Reject`), so any `CancelCast` the AI +/// emits comes from `search::fallback_action`. That function has several +/// `CancelCast` exits — `TargetSelection`, the pending-cast dead-end, +/// `EquipTarget`, and `Crew/Saddle/StationTarget` — but on these two boards (no +/// Equipment, no Vehicle, and the only targeting effect is a +/// `GainLife { player: Controller }` that takes no target) the pending-cast +/// dead-end is the only reachable one, so a `CancelCast` here IS that dead-end. +/// Unlike the removed `debug_assert`, this holds in release builds too. +/// +/// Both outcomes are checked. `run_ai_actions` only pushes an `AiActionResult` +/// once `apply_interaction` succeeded (`auto_play.rs:214-250`), and the +/// pending-cast `CancelCast` is offered to the AI only by +/// `semantic_candidate_actions_with_probe`'s guarded push +/// (`engine/src/ai_support/candidates.rs`, which requires `has_pending_cast` AND +/// `allows_cancel_cast`; `candidate_actions_broad_with_probe`, which it calls, +/// emits `CancelCast` only for Equipment/Vehicle/modal shapes absent from these +/// boards). A dead-end satisfying only `allows_cancel_cast` therefore never +/// becomes an applied action — it lands in `break_reason`, and a results-only +/// assertion would miss it. +fn assert_no_fallback_cancel(run: &phase_ai::auto_play::AiActionsRun, what: &str) { + use phase_ai::auto_play::AiActionsBreakReason; + + assert!( + !run.results + .iter() + .any(|r| matches!(r.action, GameAction::CancelCast)), + "{what}: AI escaped via fallback CancelCast (actions: {:?})", + run.results.iter().map(|r| &r.action).collect::>(), + ); assert!( - results.len() <= 200, - "AI loop must stay within its safety cap and never dead-end" + !matches!( + &run.break_reason, + Some(AiActionsBreakReason::ApplyFailed { action, .. }) + if matches!(**action, GameAction::CancelCast) + ), + "{what}: AI dead-ended on an unapplied fallback CancelCast ({:?})", + run.break_reason, ); } @@ -1059,9 +1133,13 @@ fn scenario_claws_of_gix_witness_board_does_not_dead_end() { /// sacrifice, so the Claws activation is LEGAL and the AI loop completes it /// without dead-ending. REVERT-FAILING: reverting the mana-first detour restores /// the sacrifice-first ordering, where `can_pay` is rejected (or the activation -/// dead-ends), so `legal_actions` no longer surfaces the Claws activation and the -/// pending-cost loop panics at `search.rs` "AI fallback reached during pending -/// cast (variant PayCost, spell Claws of Gix)" — the baseline seed-19057 abort. +/// dead-ends), so `legal_actions` no longer surfaces the Claws activation — the +/// `activation_legal_for` precondition below is what fails, and the pending-cost +/// loop then escapes through `fallback_action`'s `CancelCast`, which +/// [`assert_no_fallback_cancel`] catches. (That branch used to `debug_assert!` +/// with the message "AI fallback reached during pending cast …"; that string no +/// longer exists — the surviving `tracing::error!` reads "AI fallback cancelled +/// an uncompletable cast".) #[test] fn scenario_claws_of_gix_mana_first_board_proposes_and_completes() { let mut scenario = GameScenario::new(); @@ -1100,8 +1178,8 @@ fn scenario_claws_of_gix_mana_first_board_proposes_and_completes() { "mana-first pays {{1}} on the intact 3-artifact board → Claws activation must be legal" ); - // Driving the full loop must COMPLETE without reaching the `fallback_action` - // dead-end panic. + // Driving the full loop must COMPLETE without escaping through + // `fallback_action` — see `assert_no_fallback_cancel`. let ai_players = HashSet::from([P0]); let ai_configs = HashMap::from([(P0, create_config(AiDifficulty::VeryHard, Platform::Native))]); let mut ai_rng = SmallRng::seed_from_u64(19057); @@ -1113,9 +1191,21 @@ fn scenario_claws_of_gix_mana_first_board_proposes_and_completes() { &mut ai_rng, &ai_session, ); + assert_no_fallback_cancel(&results, "mana-first board must not dead-end the AI loop"); + // Positive half: "completes" must mean the activation actually happened, not + // merely that nothing cancelled. Without it the test would also pass on a board + // the AI simply passes priority on — which is what the witness sibling does. assert!( - results.len() <= 200, - "mana-first board must not dead-end the AI loop" + results + .results + .iter() + .any(|r| matches!(r.action, GameAction::ActivateAbility { .. })), + "mana-first board must ACTIVATE the Claws (actions: {:?})", + results + .results + .iter() + .map(|r| &r.action) + .collect::>(), ); }