diff --git a/crates/athena-sim/src/clock.rs b/crates/athena-sim/src/clock.rs index 0747106..48169d6 100644 --- a/crates/athena-sim/src/clock.rs +++ b/crates/athena-sim/src/clock.rs @@ -1,16 +1,16 @@ //! The match clock: `Pause`/`Unpause Match Time`, `Set Match Time` and //! `Set Slow Motion` write it, `Match Time` and `Total Time Elapsed` //! read it (athena#120). An unpaused clock advances each tick by the -//! tick length scaled by the slow-motion percent: a `Pause Match Time` -//! stops `Total Time Elapsed` and the match countdown alike, and -//! `Set Slow Motion` scales how fast both run. A `Wait` maps seconds -//! to ticks the clock does not describe, so a `Wait` under a non-100 -//! factor — and a `Wait Until` whose timeout would suspend — stops -//! `not_modeled` rather than guess the mapping. `Match Time` before -//! any `Set Match Time` is unanswerable — the lobby's phase limit is -//! no input the scenario format carries — and a countdown reaching -//! zero is the phase boundary the simulator does not run. Modeled, -//! not measured (`docs/findings.md`). +//! tick length: a `Pause Match Time` stops `Total Time Elapsed` and +//! the match countdown alike. `Set Slow Motion` is recorded only at +//! the factors P8 measured (`MEASURED_SLOW_MOTION`): there `Total Time +//! Elapsed` and a `Wait(.., Ignore Condition)` read as at 100%. Any +//! other factor stops `not_modeled` at the next tick or `Wait`. +//! `Match Time` before any `Set Match Time` is +//! unanswerable — the lobby's phase limit is no input the scenario +//! format carries — and a countdown reaching zero is the phase +//! boundary the simulator does not run. The countdown and pause +//! are modeled, not measured (`docs/findings.md`). use workshop_rs::Value; @@ -20,9 +20,13 @@ use crate::step::World; use crate::unsupported; use crate::{Change, Finite, Stop, Val}; +/// The `Set Slow Motion` percents P8 measured: the 100 control and the +/// 50 and 90 factors (`probes/p8-slow-motion-wait/capture.json`). +const MEASURED_SLOW_MOTION: [f64; 3] = [100.0, 50.0, 90.0]; + /// The match clock: how far the run's game time has come, whether /// `Pause Match Time` holds it, the countdown `Match Time` reports -/// and the `Set Slow Motion` percent that scales its rate. +/// and the last `Set Slow Motion` percent. #[derive(Debug, Clone, PartialEq)] pub(crate) struct Clock { /// `Pause Match Time` holds the clock; it advances only while @@ -32,8 +36,8 @@ pub(crate) struct Clock { /// Time` writes it — the lobby's phase limit is not an input the /// scenario format carries, so the read has no start value. pub match_time: Option, - /// The `Set Slow Motion` percent; `100` is the client's normal - /// rate. + /// The last `Set Slow Motion` percent; `100` is the client's + /// normal rate. Recorded only; it scales nothing (P8). pub slow_motion: Finite, /// The game-time seconds elapsed; `Total Time Elapsed` reads the /// start offset plus this. @@ -52,19 +56,30 @@ impl Clock { } } + /// Stop unless the last `Set Slow Motion` factor is one P8 measured; + /// the simulator's 16 ms tick mapping holds only for those. + pub(crate) fn require_measured_slow_motion(&self) -> Result<(), Stop> { + let percent = self.slow_motion.get(); + if MEASURED_SLOW_MOTION.contains(&percent) { + return Ok(()); + } + unsupported(format!("Set Slow Motion at {percent}%")) + } + /// Advance the clock into a tick: an unpaused clock gains - /// `tick_s` scaled by `slow_motion` on `elapsed` and loses the - /// same on `match_time`. A paused clock stands. A countdown that - /// reaches zero crosses the phase boundary the simulator does not - /// run — game-mode advancement is not modeled — so the run stops. + /// `tick_s` on `elapsed` and loses the same on `match_time`. A + /// paused clock stands. A countdown that reaches zero crosses the + /// phase boundary the simulator does not run — game-mode + /// advancement is not modeled — so the run stops. An unmeasured + /// slow-motion factor stops the run first. pub(crate) fn advance(&mut self, tick_s: f64) -> Result<(), Stop> { + self.require_measured_slow_motion()?; if self.paused { return Ok(()); } - let step = tick_s * self.slow_motion.get() / 100.0; - self.elapsed = Finite::produced(self.elapsed.get() + step, "match clock")?; + self.elapsed = Finite::produced(self.elapsed.get() + tick_s, "match clock")?; if let Some(remaining) = self.match_time { - let remaining = remaining.get() - step; + let remaining = remaining.get() - tick_s; if remaining <= 0.0 { return unsupported("matchTime reaching zero"); } diff --git a/crates/athena-sim/src/sched.rs b/crates/athena-sim/src/sched.rs index 38f1212..d2637d7 100644 --- a/crates/athena-sim/src/sched.rs +++ b/crates/athena-sim/src/sched.rs @@ -293,57 +293,6 @@ pub(crate) fn record_stop( stop.stopped_at(location) } -/// A suspended `Wait`/`Wait Until` whose wake fires under a non-100 -/// `Set Slow Motion` factor would resume on the schedule the suspend -/// computed at 100% — the same unmeasured seconds-to-ticks mapping the -/// `wait`/`waitUntil` arms stop on, so the wake stops the run naming -/// the construct. `live` marks a `Wait Until` wake its own condition -/// re-check set this tick, which encodes no schedule. -fn stale_wake( - instance: &Instance<'_>, - rule_list: &[&Rule], - world: &mut World, - live: bool, - tick: u64, -) -> Result<(), Stop> { - if live || world.clock.slow_motion.get() == 100.0 { - return Ok(()); - } - // A `Wait Until` frame names its action; a `Wait`'s suspending - // frame sits one past it. - let (rule, at, construct) = match instance.wait_mode { - WaitMode::Until(frame) => ( - frame.rule_idx, - Some(StopIndex::Action(frame.pc)), - "waitUntil", - ), - _ => match instance.frames.last() { - Some(frame) => ( - frame.rule_idx, - Some(StopIndex::Action(frame.pc - 1)), - "wait", - ), - None => (instance.rule_idx, None, "wait"), - }, - }; - Err(record_stop( - &mut world.runs, - RuleRun { - rule, - name: rule_list[rule].name.clone(), - event_player: event_player(instance), - ended: RunEnd::Stopped, - }, - at, - NotModeled::new(format!( - "action {construct} under a {}% simulation rate", - world.clock.slow_motion.get() - )) - .at(tick) - .into(), - )) -} - fn tick_loop( mut loaded: Loaded<'_>, world: &mut World, @@ -358,8 +307,8 @@ fn tick_loop( let mut changes_recorded = 0; for tick in 0..ticks { // The match clock advances into each tick after the first: - // paused it stands, slowed it scales, and a countdown reaching - // zero ends the run before the tick's rules do any work. + // paused it stands, and a countdown reaching zero ends the run + // before the tick's rules do any work. if tick > 0 { world.clock.advance(TICK_S).map_err(|stop| stop.at(tick))?; } @@ -498,7 +447,6 @@ fn run_tick( let edge = holds && !instance.prev; instance.prev = holds; // A wake due this tick wins over the wait behavior. - let mut until_live = false; if instance.wake.is_some_and(|wake| wake > tick) { match instance.wait_mode { WaitMode::Ignore => {} @@ -554,16 +502,12 @@ fn run_tick( ) })? { instance.wake = Some(tick); - until_live = true; } } } } let start = match instance.wake { - Some(wake) if wake <= tick => { - stale_wake(instance, rule_list, world, until_live, tick)?; - true - } + Some(wake) if wake <= tick => true, Some(_) => false, None => { if edge && instance.frames.is_empty() { @@ -587,10 +531,6 @@ fn run_tick( } Event::Player { .. } => { if instance.wake.is_some_and(|wake| wake <= tick) { - // Event rules suspend only on `Wait(.., Ignore - // Condition)`, so a wake here is always the stale - // schedule `stale_wake` gates. - stale_wake(instance, rule_list, world, false, tick)?; instance.wake = None; run_and_record(instance, rule_list, blocks, subroutines, world, tick, now) .map_err(|e| e.at(tick))?; @@ -608,7 +548,6 @@ fn run_tick( // pushed onto it. A subroutine rule has no conditions, so // the wait behaviors that read them do not apply; a // `Wait Until` still re-checks its own condition. - let mut until_live = false; if instance.wake.is_some_and(|wake| wake > tick) && let WaitMode::Until(frame) = instance.wait_mode { @@ -646,11 +585,9 @@ fn run_tick( ) })? { instance.wake = Some(tick); - until_live = true; } } if instance.wake.is_some_and(|wake| wake <= tick) { - stale_wake(instance, rule_list, world, until_live, tick)?; instance.wake = None; } if instance.wake.is_none() && !instance.frames.is_empty() { diff --git a/crates/athena-sim/src/step.rs b/crates/athena-sim/src/step.rs index 534ad3e..b504d20 100644 --- a/crates/athena-sim/src/step.rs +++ b/crates/athena-sim/src/step.rs @@ -593,16 +593,8 @@ pub(crate) fn run_instance( if mode != WaitMode::Ignore && inst.event.is_some() { return unsupported("wait behavior in an event-triggered rule"); } + world.clock.require_measured_slow_motion()?; let ticks = wait_ticks(number(&eval(seconds, &env)?)?); - // The catalog's seconds-to-ticks mapping under a - // non-100 `Set Slow Motion` factor is unmeasured — - // stop rather than guess it (athena#120). - if world.clock.slow_motion.get() != 100.0 { - return unsupported(format!( - "action wait under a {}% simulation rate", - world.clock.slow_motion.get() - )); - } inst.wake = Some(tick + ticks); inst.wait_mode = mode; advance(inst); @@ -633,14 +625,7 @@ pub(crate) fn run_instance( if timeout <= 0.0 { return unsupported("Wait Until(false, 0)"); } - // The same unmeasured seconds-to-ticks mapping as - // `wait` gates a suspending `Wait Until`. - if world.clock.slow_motion.get() != 100.0 { - return unsupported(format!( - "action waitUntil under a {}% simulation rate", - world.clock.slow_motion.get() - )); - } + world.clock.require_measured_slow_motion()?; inst.wake = Some(tick + wait_ticks(timeout)); inst.wait_mode = WaitMode::Until(Frame { rule_idx, pc }); advance(inst); diff --git a/crates/athena-sim/src/timeline.rs b/crates/athena-sim/src/timeline.rs index f890608..d175975 100644 --- a/crates/athena-sim/src/timeline.rs +++ b/crates/athena-sim/src/timeline.rs @@ -142,7 +142,7 @@ pub struct TimelineEntry { pub tick: u64, /// The tick's `Total Time Elapsed` in milliseconds: 15 + the /// elapsed game-time seconds. The match clock drives it, so a - /// paused or slowed clock repeats values across ticks. + /// paused clock repeats values across ticks. pub time: Finite, pub rules: Vec, pub changes: Vec, diff --git a/crates/athena-sim/tests/fixtures.rs b/crates/athena-sim/tests/fixtures.rs index 2f25340..e52ba1f 100644 --- a/crates/athena-sim/tests/fixtures.rs +++ b/crates/athena-sim/tests/fixtures.rs @@ -160,9 +160,12 @@ fn compare_logs(trace: &Trace, captured: &Capture) -> Result<(), String> { const RUN_SECONDS: f64 = 10.0; fn check_probe(id: &str) { - let options = Options { - seconds: RUN_SECONDS, - }; + check_probe_for(id, RUN_SECONDS); +} + +/// `check_probe` for a probe whose run outlasts `RUN_SECONDS`. +fn check_probe_for(id: &str, seconds: f64) { + let options = Options { seconds }; // A probe that needs a real player carries a `scenario.json`; without // one `run_text` runs the bare program. let scenario = probe_file(id, "scenario.json") @@ -243,6 +246,12 @@ fn p6_wait_behavior() { check_probe("p6-wait-behavior"); } +#[test] +fn p8_slow_motion_wait() { + // Three factors of about 2.7 s each, after a 3 s start. + check_probe_for("p8-slow-motion-wait", 12.0); +} + #[test] fn p7_hero_settings() { check_probe("p7-hero-settings"); diff --git a/crates/athena-sim/tests/match_clock.rs b/crates/athena-sim/tests/match_clock.rs index 275270e..db07cac 100644 --- a/crates/athena-sim/tests/match_clock.rs +++ b/crates/athena-sim/tests/match_clock.rs @@ -1,11 +1,11 @@ //! The match clock (athena#120): `Pause`/`Unpause Match Time`, //! `Set Match Time` and `Set Slow Motion` write it, `Match Time` and //! `Total Time Elapsed` read it, and every write records a -//! `matchClock` change. A `Wait` — and a suspending `Wait Until` — -//! under a non-100 factor stops `not_modeled`, the seconds-to-ticks -//! mapping there being unmeasured. +//! `matchClock` change. `Set Slow Motion` is recorded only at the +//! factors P8 measured (100, 50, 90), where `Total Time Elapsed` and +//! `Wait` rounding read as at 100%; any other factor is `not_modeled`. -use athena_sim::{Change, Outcome, RunEnd, StopIndex, Val, run_scenario, run_text}; +use athena_sim::{Change, Outcome, Val, run_scenario, run_text}; /// A global rule `clock` whose actions `body` spells, with `g`/`t0`/ /// `t1`/`m` declared for reads to land in. @@ -176,43 +176,19 @@ fn a_countdown_reaching_zero_ends_the_run() { } #[test] -fn set_slow_motion_scales_the_clock_and_records_the_factor() { - // `reader` suspends at the 100% rate; `slow` then sets 50%, so the - // in-flight `Wait Until` re-check sees one 8 ms tick, not 16. - let text = r#" -variables { - global: - 0: hit -} - -rule ("reader") { - event { - Ongoing - Global; - } - actions { - Wait Until(Total Time Elapsed >= 0.023, 999); - Set Global Variable(hit, Total Time Elapsed); - } -} - -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(50); - } -} -"#; - let trace = run_text(text, athena_sim::Options { seconds: 1.0 }).unwrap(); +fn set_slow_motion_records_the_factor_and_leaves_game_time_unscaled() { + // P8 (measured): under 50% and 90% the Inspector clock still reads + // 16 ms per tick, so a rule sees no change in `Total Time Elapsed`. + let trace = run( + " Set Slow Motion(50); + Set Global Variable(t0, Total Time Elapsed); + Wait(0.016, Ignore Condition); + Set Global Variable(t1, Total Time Elapsed);", + 1.0, + ); assert_eq!(trace.outcome, Outcome::Complete); - assert_eq!(trace.globals["hit"], Val::number(0.023)); - let [start, wake] = trace.timeline.entries.as_slice() else { - panic!("expected two entries, got {:?}", trace.timeline.entries); - }; - assert_eq!((start.tick, start.time.get()), (0, 15.0)); - assert_eq!((wake.tick, wake.time.get()), (1, 23.0)); - assert_eq!(wake.rules[0].ended, RunEnd::Finished); + assert_eq!(trace.globals["t0"], Val::number(0.015)); + assert_eq!(trace.globals["t1"], Val::number(0.031)); assert_eq!( clock_changes(&trace, 0), [Change::MatchClock { @@ -224,350 +200,256 @@ rule ("slow") { ); } -#[test] -fn a_wait_under_a_non_100_factor_is_not_modeled() { - let trace = run( - " Set Slow Motion(90); - Wait(1, Ignore Condition);", - 1.0, - ); +/// Factors P8 did not measure. +const UNMEASURED: [u32; 2] = [10, 200]; + +/// Assert the run stopped `not_modeled` on an unmeasured slow-motion +/// factor, naming it. +fn assert_unmeasured_stop(trace: &athena_sim::Trace, factor: u32) { let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); + panic!("{factor}%: expected NotModeled, got {:?}", trace.outcome); }; assert_eq!( not_modeled.construct, - "action wait under a 90% simulation rate" + format!("Set Slow Motion at {factor}%") ); - assert_eq!(not_modeled.tick, Some(0)); - let Some(location) = ¬_modeled.location else { - panic!("expected a stop location"); - }; - assert_eq!(location.at, Some(StopIndex::Action(1))); } -#[test] -fn a_suspending_wait_until_under_a_non_100_factor_is_not_modeled() { - let trace = run( - " Set Slow Motion(50); - Wait Until(False, 1);", - 1.0, - ); +/// Assert the stop happened at `tick`: tick 0 proves a `step.rs` gate, +/// since the clock gate cannot stop before tick 1. +fn assert_stopped_at_tick(trace: &athena_sim::Trace, tick: u64) { let Outcome::NotModeled(not_modeled) = &trace.outcome else { panic!("expected NotModeled, got {:?}", trace.outcome); }; - assert_eq!( - not_modeled.construct, - "action waitUntil under a 50% simulation rate" - ); + assert_eq!(not_modeled.tick, Some(tick)); } #[test] -fn a_true_wait_until_under_a_non_100_factor_still_passes() { - // The gate covers the suspend only — a condition already true - // continues in the same tick, no timing is guessed. - let trace = run( - " Set Slow Motion(50); - Wait Until(True, 1); - Set Global Variable(g, 1);", - 1.0, - ); - assert_eq!(trace.outcome, Outcome::Complete); - assert_eq!(trace.globals["g"], Val::number(1.0)); +fn waits_under_a_measured_factor_round_up_to_whole_ticks() { + // P8 (measured): at 50% and 90% a `Wait(0.1)` still takes 112 ms. + for factor in [50, 90] { + let trace = run( + &format!( + " Set Slow Motion({factor}); + Wait(0.1, Ignore Condition); + Set Global Variable(t0, Total Time Elapsed);" + ), + 1.0, + ); + assert_eq!(trace.outcome, Outcome::Complete, "{factor}%"); + assert_eq!(trace.globals["t0"], Val::number(0.127), "{factor}%"); + } } #[test] -fn a_wait_suspended_before_the_factor_change_stops_at_its_wake() { - // `A` suspends at the 100% rate; `slow` then sets 50%, so the wake - // tick encodes the same unmeasured seconds-to-ticks mapping — the - // run stops there rather than resume on it. - let text = r#" -variables { - global: - 0: g -} - -rule ("A") { - event { - Ongoing - Global; - } - actions { - Wait(0.048, Ignore Condition); - Set Global Variable(g, Total Time Elapsed); +fn a_wait_under_an_unmeasured_factor_is_not_modeled() { + for factor in UNMEASURED { + let trace = run( + &format!( + " Set Slow Motion({factor}); + Wait(0.1, Ignore Condition);" + ), + 1.0, + ); + assert_unmeasured_stop(&trace, factor); + assert_stopped_at_tick(&trace, 0); } } -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(50); +#[test] +fn a_suspending_wait_until_under_an_unmeasured_factor_is_not_modeled() { + for factor in UNMEASURED { + let trace = run( + &format!( + " Set Slow Motion({factor}); + Wait Until(False, 0.1);" + ), + 1.0, + ); + assert_unmeasured_stop(&trace, factor); + assert_stopped_at_tick(&trace, 0); } } -"#; - let trace = run_text(text, athena_sim::Options { seconds: 1.0 }).unwrap(); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "action wait under a 50% simulation rate" - ); - assert_eq!(not_modeled.tick, Some(3)); - let Some(location) = ¬_modeled.location else { - panic!("expected a stop location"); - }; - assert_eq!( - (location.rule, location.at), - (0, Some(StopIndex::Action(0))) - ); -} #[test] -fn a_wait_until_timeout_expiring_under_a_non_100_factor_is_not_modeled() { - // The suspended `Wait Until`'s timeout is the same stale schedule: - // the condition stays false and the expiry fires under 50%. - let text = r#" -rule ("u") { - event { - Ongoing - Global; - } - actions { - Wait Until(False, 0.048); +fn a_wait_until_timeout_under_a_measured_factor_keeps_the_16_ms_ticks() { + for factor in [50, 90] { + let trace = run( + &format!( + " Set Slow Motion({factor}); + Wait Until(False, 0.1); + Set Global Variable(t0, Total Time Elapsed);" + ), + 1.0, + ); + assert_eq!(trace.outcome, Outcome::Complete, "{factor}%"); + assert_eq!(trace.globals["t0"], Val::number(0.127), "{factor}%"); } } -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(50); +#[test] +fn an_unmeasured_factor_stops_the_clock_even_with_no_wait() { + for factor in UNMEASURED { + let trace = run(&format!(" Set Slow Motion({factor});"), 1.0); + assert_unmeasured_stop(&trace, factor); + let Outcome::NotModeled(not_modeled) = &trace.outcome else { + unreachable!() + }; + assert_eq!(not_modeled.tick, Some(1), "the clock stops the next tick"); } } -"#; - let trace = run_text(text, athena_sim::Options { seconds: 1.0 }).unwrap(); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "action waitUntil under a 50% simulation rate" - ); - assert_eq!(not_modeled.tick, Some(3)); - let Some(location) = ¬_modeled.location else { - panic!("expected a stop location"); - }; - assert_eq!( - (location.rule, location.at), - (0, Some(StopIndex::Action(0))) + +#[test] +fn a_paused_clock_under_an_unmeasured_factor_is_not_modeled() { + let trace = run( + " Pause Match Time; + Set Slow Motion(10);", + 1.0, ); + assert_unmeasured_stop(&trace, 10); +} + +/// A rule that sets `factor` in the tick after `waiter` suspends at +/// 100%: the resume path must stop at the wake, not run the stale +/// schedule. +fn slow_rule(factor: u32) -> String { + format!( + r#" +rule ("slow") {{ + event {{ + Ongoing - Global; + }} + actions {{ + Set Slow Motion({factor}); + }} +}} +"# + ) } #[test] -fn a_wait_until_condition_wake_under_a_non_100_factor_resumes() { - // The one bypass of the stale-wake gate: a `Wait Until` wake its - // own condition re-check produced this tick encodes no schedule, - // so it resumes even under 50%. `waiter` suspends at 100%, `slow` - // sets 50% at tick 1, `setter` writes `g` at tick 3 — the next - // re-check wakes the run and it completes. - let text = r#" -variables { +fn an_ongoing_wait_suspended_before_an_unmeasured_factor_stops() { + for factor in UNMEASURED { + let text = format!( + r#" +variables {{ global: 0: g - 1: h -} +}} -rule ("waiter") { - event { +rule ("A") {{ + event {{ Ongoing - Global; - } - actions { - Wait Until(g == 1, 999); - Set Global Variable(h, 7); + }} + actions {{ + Wait(0.048, Ignore Condition); + Set Global Variable(g, 1); + }} +}} +{}"#, + slow_rule(factor) + ); + let trace = run_text(&text, athena_sim::Options { seconds: 1.0 }).unwrap(); + assert_unmeasured_stop(&trace, factor); + assert_eq!(trace.globals["g"], Val::Null, "{factor}%: no resume"); } } -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Wait(0.016, Ignore Condition); - Set Slow Motion(50); - } -} +#[test] +fn an_event_rule_wait_suspended_before_an_unmeasured_factor_stops() { + for factor in UNMEASURED { + let text = format!( + r#" +variables {{ + global: + 0: g +}} -rule ("setter") { - event { +rule ("died") {{ + event {{ Player Died; All; All; - } - actions { + }} + actions {{ + Wait(0.032, Ignore Condition); Set Global Variable(g, 1); + }} +}} +{}"#, + slow_rule(factor) + ); + let scenario = r#"{ + "scenarioVersion": 1, + "seconds": 1, + "players": [{ "id": "p1", "hero": "ana", "team": "team1" }], + "events": [{ "kind": "playerDied", "time": 0, "eventPlayer": "p1" }] + }"#; + let trace = run_scenario(&text, scenario).unwrap_or_else(|error| panic!("{error}")); + assert_unmeasured_stop(&trace, factor); + assert_eq!(trace.globals["g"], Val::Null, "{factor}%: no resume"); } } -"#; - let scenario = r#"{ - "scenarioVersion": 1, - "seconds": 1, - "players": [{ "id": "p1", "hero": "ana", "team": "team1" }], - "events": [{ "kind": "playerDied", "time": 0.048, "eventPlayer": "p1" }] - }"#; - let trace = run_scenario(text, scenario).unwrap_or_else(|error| panic!("{error}")); - assert_eq!(trace.outcome, Outcome::Complete); - assert_eq!(trace.globals["h"], Val::number(7.0)); -} #[test] -fn a_subroutine_wait_until_condition_wake_under_a_non_100_factor_resumes() { - // The same carve-out on a `Start Rule`'d subroutine instance: - // `sub` suspends on the `Wait Until` at 100% at tick 0, `slow` - // sets 50% the same tick, and the re-check wake after `setter` - // writes `g` resumes through to `h`. - let text = r#" -variables { +fn a_subroutine_wait_suspended_before_an_unmeasured_factor_stops() { + for factor in UNMEASURED { + let text = format!( + r#" +variables {{ global: 0: g - 1: h -} +}} -subroutines { +subroutines {{ 0: sub -} +}} -rule ("start") { - event { +rule ("start") {{ + event {{ Ongoing - Global; - } - actions { + }} + actions {{ Start Rule(sub, Do Nothing); - } -} + }} +}} -rule ("Subroutine sub") { - event { +rule ("Subroutine sub") {{ + event {{ Subroutine; sub; - } - actions { - Wait Until(g == 1, 999); - Set Global Variable(h, 9); - } -} - -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(50); - } -} - -rule ("setter") { - event { - Player Died; - All; - All; - } - actions { - Set Global Variable(g, 1); - } -} -"#; - let scenario = r#"{ - "scenarioVersion": 1, - "seconds": 1, - "players": [{ "id": "p1", "hero": "ana", "team": "team1" }], - "events": [{ "kind": "playerDied", "time": 0.048, "eventPlayer": "p1" }] - }"#; - let trace = run_scenario(text, scenario).unwrap_or_else(|error| panic!("{error}")); - assert_eq!(trace.outcome, Outcome::Complete); - assert_eq!(trace.globals["h"], Val::number(9.0)); -} - -#[test] -fn an_event_rule_wait_suspended_before_the_factor_change_stops() { - // The event-rule resume path gates the same way: the `Player Died` - // run suspends at 100%, `slow` sets 50%, the wake tick is stale. - let text = r#" -rule ("died") { - event { - Player Died; - All; - All; - } - actions { + }} + actions {{ Wait(0.032, Ignore Condition); + Set Global Variable(g, 1); + }} +}} +{}"#, + slow_rule(factor) + ); + let trace = run_text(&text, athena_sim::Options { seconds: 1.0 }).unwrap(); + assert_unmeasured_stop(&trace, factor); + assert_eq!(trace.globals["g"], Val::Null, "{factor}%: no resume"); } } -rule ("slow") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(50); - } -} -"#; - let scenario = r#"{ - "scenarioVersion": 1, - "seconds": 1, - "players": [{ "id": "p1", "hero": "ana", "team": "team1" }], - "events": [{ "kind": "playerDied", "time": 0, "eventPlayer": "p1" }] - }"#; - let trace = run_scenario(text, scenario).unwrap_or_else(|error| panic!("{error}")); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "action wait under a 50% simulation rate" - ); - assert_eq!(not_modeled.tick, Some(2)); - let Some(location) = ¬_modeled.location else { - panic!("expected a stop location"); - }; - assert_eq!( - (location.rule, location.at, location.event_player.as_deref()), - (0, Some(StopIndex::Action(0)), Some("p1")) - ); -} - #[test] -fn a_subroutine_wait_suspended_before_the_factor_change_stops() { - // `Start Rule` puts the subroutine's run on its own instance; a - // `Wait` it suspends on gates the same at its wake. +fn a_wait_until_condition_wake_under_a_non_100_factor_resumes_on_the_next_tick() { + // The ongoing-rule re-check wakes on the condition, not a schedule: + // at 50% the clock still reads 31 ms on tick 1 (P8). let text = r#" variables { global: - 0: g -} - -subroutines { - 0: sub + 0: hit } -rule ("start") { +rule ("reader") { event { Ongoing - Global; } actions { - Start Rule(sub, Do Nothing); - } -} - -rule ("Subroutine sub") { - event { - Subroutine; - sub; - } - actions { - Wait(0.032, Ignore Condition); - Set Global Variable(g, 1); + Wait Until(Total Time Elapsed >= 0.023, 999); + Set Global Variable(hit, Total Time Elapsed); } } @@ -581,21 +463,13 @@ rule ("slow") { } "#; let trace = run_text(text, athena_sim::Options { seconds: 1.0 }).unwrap(); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "action wait under a 50% simulation rate" - ); - assert_eq!(not_modeled.tick, Some(2)); - let Some(location) = ¬_modeled.location else { - panic!("expected a stop location"); + assert_eq!(trace.outcome, Outcome::Complete); + assert_eq!(trace.globals["hit"], Val::number(0.031)); + let [start, wake] = trace.timeline.entries.as_slice() else { + panic!("expected two entries, got {:?}", trace.timeline.entries); }; - assert_eq!( - (location.rule, location.at), - (1, Some(StopIndex::Action(0))) - ); + assert_eq!((start.tick, start.time.get()), (0, 15.0)); + assert_eq!((wake.tick, wake.time.get()), (1, 31.0)); } #[test] @@ -612,69 +486,3 @@ fn a_non_finite_clock_argument_is_not_modeled() { ); } } - -/// A finite `Set Slow Motion` factor so large that a few thousand ticks -/// of `tick_s * factor` overflow `elapsed`: the next `advance` stops -/// `not_modeled` instead of writing `inf` into `Total Time Elapsed` -/// (athena#133). The ticks in between are quiet — the run stops on the -/// clock itself, not on a rule. -#[test] -fn a_slow_motion_factor_that_overflows_the_elapsed_clock_is_not_modeled() { - let trace = run( - " Set Slow Motion(Multiply(Raise To Power(10, 308), 1.5)); - Set Global Variable(g, 1);", - 121.0, - ); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "match clock produced a non-finite number" - ); -} - -/// The timeline's `time` field is `now * 1000`: an elapsed clock that -/// still fits in seconds can overflow in milliseconds. A player event -/// landing on a tick whose timeline `time` is `inf` stops `not_modeled` -/// (athena#133). -#[test] -fn a_timeline_time_that_overflows_is_not_modeled() { - let text = r#" -variables { - global: - 0: g -} - -rule ("clock") { - event { - Ongoing - Global; - } - actions { - Set Slow Motion(Multiply(Raise To Power(10, 308), 1.5)); - } -} - -rule ("join") { - event { - Player Joined Match; - All; - All; - } - actions { - Set Global Variable(g, 1); - } -} -"#; - let scenario = r#"{ "scenarioVersion": 1, "seconds": 1, - "players": [{ "id": "p1", "host": true, "hero": "ana" }], - "events": [{ "kind": "playerJoined", "time": 0.2, "eventPlayer": "p1" }] }"#; - let trace = run_scenario(text, scenario).unwrap_or_else(|error| panic!("{error}")); - let Outcome::NotModeled(not_modeled) = &trace.outcome else { - panic!("expected NotModeled, got {:?}", trace.outcome); - }; - assert_eq!( - not_modeled.construct, - "match clock produced a non-finite number" - ); -} diff --git a/docs/architecture.md b/docs/architecture.md index 0244c2d..7f17c1d 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -123,5 +123,6 @@ The simulator makes these choices only to stay deterministic; each needs a probe - **Empty world, modeled not measured** — the geometry reads (athena#77, the `athena#75` decision); no capture covers them and the goal excludes real geometry: - The run has no map geometry, and the trace marks it as `geometry: "emptyWorld"` so the viewer can warn that geometry-dependent results are not real. A raycast never hits and answers by the catalog's documented no-hit return: `Ray Cast Hit Position` the end position, `Ray Cast Hit Player` `Null`, `Ray Cast Hit Normal` the direction from the end back to the start — a zero-length cast is `not_modeled`. `Is In Line of Sight` is true; `Nearest Walkable Position` yields its input; `Is On Ground` is true and `Is In Air`/`Is On Wall`/`Is In Spawn Room` are false — an empty world has none of what they ask about. `Is In Spawn Room` is also a version-2 `state` read: a player that declares `state` answers `state.isInSpawnRoom` instead of the empty world's `false` (athena#89). - `Teleport` writes the player's scenario `position` to the evaluated destination (`Null` is the origin, the catalog's `zeroAsNull` coercion) and records a `world` change with `field` `position`; `Position Of` reads the new value. `Apply Impulse` changes velocity, which needs physics, and stays `not_modeled`, as does `Is Standing`. `Is Moving` and `Eye Position` are version-2 `state` reads instead (athena#89): a player that declares `state` answers `state.isMoving`/`state.eyePosition`, and a player without `state` reports a `missing_input`. -- **Modeled, not measured** — the match clock (athena#120); no capture covers it: - - `Pause`/`Unpause Match Time`, `Set Match Time` and `Set Slow Motion` write the run's clock: an unpaused clock advances each tick by 16 ms scaled by the slow-motion percent, on `Total Time Elapsed` and the `Match Time` countdown alike; `Pause` holds it. `Match Time` has no start value — the lobby's phase limit is not an input the scenario format carries — so a read before a `Set Match Time` is `not_modeled`, and a countdown reaching zero ends the run, the phase boundary it crosses being unmodeled. Every write records a `matchClock` change. A `Wait` under a non-100 factor is `not_modeled` — the seconds-to-ticks mapping there is unmeasured — as is a `Wait Until` whose timeout would suspend, and a wake a 100%-rate suspension scheduled that fires after the factor moved stops the same way. +- **Measured** — `Set Slow Motion` (P8): at factors 50 and 90 `Total Time Elapsed` still advances 16 ms per tick, a `Wait(.., Ignore Condition)` rounds up to whole 16 ms ticks and the Inspector timestamps read as at 100%. Measured at 50% and 90% with the 100% control; the simulator records the write as a `matchClock` change and runs the clock and `Wait`s on unscaled 16 ms ticks at those factors only. Any other factor ends the run `not_modeled` at the next tick, `Wait` or `Wait Until` that would use it. Not measured: the wall-clock ratio and the cause of the unchanged readings (the game was seen to slow, by eye, with no external timer). +- **Modeled, not measured** — the rest of the match clock (athena#120); no capture covers it: + - `Pause`/`Unpause Match Time` and `Set Match Time` write the run's clock: an unpaused clock advances each tick by 16 ms, on `Total Time Elapsed` and the `Match Time` countdown alike; `Pause` holds it. `Match Time` has no start value — the lobby's phase limit is not an input the scenario format carries — so a read before a `Set Match Time` is `not_modeled`, and a countdown reaching zero ends the run, the phase boundary it crosses being unmodeled. Every write records a `matchClock` change. diff --git a/docs/findings.md b/docs/findings.md index 6cef97f..6dd98d8 100644 --- a/docs/findings.md +++ b/docs/findings.md @@ -59,4 +59,4 @@ Simulator choices no capture backs yet — the detail lives in [architecture.md] - State cells and stored modifiers (athena#116): the version-2 `state` map gains a write side — a state-write action writes a cell over the declared map, a write defines a key the scenario never supplied, a read after a write returns the written value, and a read before any write of an undeclared key stays `missing_input`; every write records a `state` change (`player`, `key`, `old`, `new`). The writes, each by its catalog sentence: `setUltCharge` writes `ultCharge` ("sets the ultimate charge for one or more players as a percentage of maximum charge"), the `Number|Boolean` parameter reading `False`/`True` as `0`/`1`; `setHealth` ("sets the health of a player or players … This action only has an effect on living players. For dead players, use the Resurrect action instead") writes `health`, gated by the `isDead` read — a dead target is skipped, an unanswerable `isDead` is a `missing_input`; `setMaxHealth` ("as a percentage of their max health … will ensure that a player's current health will not exceed the new max health") writes `maxHealth` off the current-max read and clamps `health`; `kill`, `respawn` and `resurrect` write `isDead` — `respawn` also `health` to the `maxHealth` read ("with full health"), its spawn relocation not simulated — and `setFacing` `To World` writes the scenario `facing` to the direction's angles (`To Player` stays `not_modeled`: the catalog does not state the composition). The stored modifiers record a `modifier` change (action, player, evaluated non-target arguments) and land on the player's `modifiers` — nothing reads them back and no readable value moves: `setUltEnabled` → `ultEnabled`, `setAbility1Enabled`/`setAbility2Enabled` → `ability1Enabled`/`ability2Enabled`, `setDamageDealt`/`setDamageReceived`/`setHealingDealt`/`setHealingReceived` → `damageDealt`/`damageReceived`/`healingDealt`/`healingReceived` (scales on damage the model does not run), `setMoveSpeed`/`setGravity`/`setKnockbackReceived` → `moveSpeed`/`gravity`/`knockbackReceived` (movement modifiers no modeled read consumes — `isMoving`/`getSpeed` are scenario state, never derived from them), `setAllowedHeroes` → `allowedHeroes` (no hero read consults the list), `startForcingHero`/`stopForcingCurrentHero` → `forcedHero` written/removed, and `startForcingSpawn` → `forcedSpawnRoom` on each player of the team. The rest of PR #104's list — and the sibling ids in the same families (`stopDamageOverTime`, `stopAllDamageOverTime`, `stopAllHealingOverTime`, `stopFacing`, the player-variable `Chase *`) — stays `not_modeled`, each needing a model the run does not carry: the health-pool ids and composition (`addHealthPool`, `removeHealthPool`), the damage/heal-over-time and damage-modification ids (`startDamageOverTime`, `stopDamageOverTime`, `stopAllDamageOverTime`, `startHealingOverTime`, `stopHealingOverTime`, `stopAllHealingOverTime`, `startDamageModification`), the roster (`createDummyBot`, `destroyAllDummies`, `removeFromGame`), the entity ids (`createIcon`, `destroyAllIcons`) and text ids (`createInWorldText`, `createProgressBarInWorldText`, `destroyInWorldText`, `destroyProgressBarInWorldText`, `destroyAllInWorldText`), button and throttle forcing (`forceButtonPress`, `startForcingButton`, `stopForcingButton`, `startForcingThrottle`, `stopForcingThrottle`, `startThrottleInDirection`, `stopThrottleInDirection`), `cancelPrimaryAction` (the stun's duration is unstated), the dynamics of position, velocity and facing (`applyImpulse`, `startAcceleration`, `stopAcceleration`, `startFacing`, `stopFacing`, `startForcingPosition`, `stopForcingPosition`, `attachTo`, `detach`), the match clock and match state (`pauseMatchTime`, `unpauseMatchTime`, `setMatchTime`, `setSlowMotion`, `declareTeamVictory`, `restartMatch`), and the `Chase *` schedules (`chasePlayerVariableAtRate`, `chasePlayerVariableOverTime`, `chaseGlobalVariableAtRate`, `chaseGlobalVariableOverTime`). No capture covers any of these; modeled, not measured. - Entity-creating display actions (athena#118): every display-entity create is recorded — `createHudText`, `progressBarHud`, `createInWorldText` and `createProgressBarInWorldText` on `hud`, `createEffect`, `createBeamEffect`, `createIcon`, `createProjectileEffect` and `playEffect` on `effects` — each with the catalog sentence's arguments and the evaluated `Visible To` recipients. Two id spaces follow the catalog's sentences: the four text creates share the `TextId` space `lastTextId` and the text destroys read (`getNumberOfTextIds` counts the live elements of those kinds), and the durable entity creates share the `EntityId` space `lastCreatedEntity` reads — a `playEffect` hands out none ("the last created entity" needs a create, not a play) and dies on its tick. `entityExists` answers the `Player|EntityId` union: a scenario player exists for the whole run; a number answers from the entity table — live entity of that id or not, so a text id or unknown id is a plain `false`, `Null` is `false`, and anything else is `not_modeled`. The destroy scoping is the catalog's: `destroyEffect`/`destroyAllEffects` name both `createEffect` and `createBeamEffect`, `destroyIcon`/`destroyAllIcons` the icons, and the two in-world destroy pairs their own kinds; a `projectileEffect` is durable but no destroy action names it, and `getNumberOfEntityIds` counts only `effect`/`beam`/`icon` — the kinds the catalog's sentence lists. The catalog defines no `Set ...`/`Update ...` action taking a text or entity id, so nothing mutates an element after creation. No capture covers any of this; modeled, not measured. - Player events (athena#47): scenario `events` and the modeled state changes both drive `Event::Player` rules — a `Damage` raises `Player Took Damage` on the target and `Player Dealt Damage` on a player dealer, a hit that empties the `health` pool adds `Player Died` on the target and `Player Dealt Final Blow` on a player dealer, and a `Heal` raises `Player Received Healing`/`Player Dealt Healing`, delivered in occurrence order; a `Null` dealer raises no dealt-side event and binds `Attacker` to `null`. A rule's `team`/player filters apply to the event's player as for an injected event, and a busy instance queues the event until its run is idle. A raised event binds `Attacker`, `Victim` and `Event Damage`/`Event Healing` to its cause; an event value the cause does not bind (`Event Was Critical Hit`, `Event Was Environment`, `Event Was Health Pack`) is `not_modeled` — no scenario `values` path exists for a raised event, so the read is never a `missing_input`. One liveness read gates `Damage`, `Heal` and `Resurrect`: the `isDead` read — a state cell or the declared `state.isDead` — that `Is Alive`/`Is Dead`/`Set Player Health` share, with the health pool deciding only where `isDead` cannot answer; a dead target's pools do not move and no events raise. A killing `Damage` writes the `isDead` cell; the revive's health-pool refill follows the catalog's split — `Respawn` refills unconditionally ("with full health, even if they were already alive"), `Resurrect` only when it actually revives a dead target, a living target keeping its partial health — so a revived player can die again. One tick's raised events are bounded at 1024 against a triggering rule's own `Damage`/`Heal` fan-out. No capture covers any of it; modeled, not measured. -- The match clock (athena#120): `Pause`/`Unpause Match Time`, `Set Match Time` and `Set Slow Motion` write a clock the run carries — a paused flag, a `Match Time` countdown and a slow-motion percent. An unpaused clock advances each tick by 16 ms scaled by the percent, on `Total Time Elapsed` and the countdown alike; a paused clock stands. `Total Time Elapsed` is the 15 ms start offset plus the elapsed game time; `Match Time` reads the countdown — a read before any `Set Match Time` is `not_modeled`, the lobby's phase limit being no input the scenario format carries, and a countdown reaching zero stops the run, the phase boundary it crosses being unmodeled. Every write records a `matchClock` change (`action`, `field` — `paused`, `matchTime` or `slowMotion` — `old`, `new`). How `Wait` seconds map to ticks under a non-100 factor is unmeasured, so a `Wait` — and a `Wait Until` whose timeout would suspend — then stops `not_modeled` naming the construct, and a wait suspended at 100% whose wake fires after the factor moved stops the same way, the wake encoding the same unmeasured mapping (a `Wait Until` wake its own condition re-check produced carries no schedule and still resumes). A clock argument that evaluates non-finite is `not_modeled` too. Status expiries compare `until` against the clock-driven `now`, so `Pause Match Time` freezes a `Has Status` expiry and `Set Slow Motion` slows it — the coupling is modeled, not measured. The `Is Match In Overtime` read stays `not_modeled`. +- The match clock (athena#120): `Pause`/`Unpause Match Time`, `Set Match Time` and `Set Slow Motion` write a clock the run carries — a paused flag, a `Match Time` countdown and the last slow-motion percent. An unpaused clock advances each tick by 16 ms, on `Total Time Elapsed` and the countdown alike; a paused clock stands. `Set Slow Motion` is recorded only (P8): `Total Time Elapsed` stays 16 ms per tick and a `Wait(.., Ignore Condition)` rounds up to whole 16 ms ticks under 50% and 90% as at 100% (measured at 50% and 90% with the 100% control). Any other factor is `not_modeled`. The wall-clock ratio and the cause are not measured (the game was seen to slow by eye, with no external timer). The pause and the countdown are modeled, not measured. `Total Time Elapsed` is the 15 ms start offset plus the elapsed game time; `Match Time` reads the countdown — a read before any `Set Match Time` is `not_modeled`, the lobby's phase limit being no input the scenario format carries, and a countdown reaching zero stops the run, the phase boundary it crosses being unmodeled. Every write records a `matchClock` change (`action`, `field` — `paused`, `matchTime` or `slowMotion` — `old`, `new`). A clock argument that evaluates non-finite is `not_modeled` too. Status expiries compare `until` against the clock-driven `now`, so `Pause Match Time` freezes a `Has Status` expiry — the coupling is modeled, not measured; `Set Slow Motion` does not move it at the measured factors, since no clock a rule can read moves. The `Is Match In Overtime` read stays `not_modeled`. diff --git a/docs/trace-format.md b/docs/trace-format.md index f53ebc9..eb7c0dd 100644 --- a/docs/trace-format.md +++ b/docs/trace-format.md @@ -13,7 +13,7 @@ Each entry: | Field | Meaning | | --- | --- | | `tick` | The tick. | -| `time` | The tick's `Total Time Elapsed` in milliseconds: 15 + the run's elapsed game time (tick·16 at the normal rate). The match clock drives it — `Pause Match Time` holds it and `Set Slow Motion` scales its advance — so a paused or slowed clock repeats values across ticks. | +| `time` | The tick's `Total Time Elapsed` in milliseconds: 15 + the run's elapsed game time (tick·16 at the normal rate). The match clock drives it — `Pause Match Time` holds it, so a paused clock repeats values across ticks; `Set Slow Motion` does not change it at the measured factors 50 and 90; any other factor ends the run `not_modeled`. | | `rules` | The rule executions that started, resumed or ended on the tick, in execution order. See below. | | `changes` | The state changes the executions made, in execution order across rules. See below. | @@ -41,7 +41,7 @@ Each `changes` element has `kind` plus its own fields; `old`/`new` serialize as | `randomDraw` | `rule`, `construct`, `value` | A `Random *` value drew from the scenario's `random` source: `rule` is the index of the rule the value belongs to (as in `rules`; inside `Call Subroutine`, the subroutine's own), `construct` the value id, `value` the produced value. | | `state` | `player`, `key`, `old`, `new` | A state-cell write (see State-cell writes in [simulator-interface.md](simulator-interface.md#state-cell-writes-and-stored-modifiers)): `key` is the `state` key (`ultCharge`, `health`, `isDead`, …); `old` is what the key read before the write — the earlier write, the declared `state` entry or the established fallback — `null` when nothing answered it. | | `modifier` | `player`, `action`, `args` | A stored-modifier action applied to a player: `action` is the action id, `args` the evaluated non-target arguments. The modifier changes no readable value. | -| `matchClock` | `action`, `field`, `old`, `new` | A match-clock write: `action` is the action id, `field` is `paused` (`Pause`/`Unpause Match Time`), `matchTime` (`Set Match Time`; `old` is `null` until a first write) or `slowMotion` (`Set Slow Motion`). | +| `matchClock` | `action`, `field`, `old`, `new` | A match-clock write: `action` is the action id, `field` is `paused` (`Pause`/`Unpause Match Time`), `matchTime` (`Set Match Time`; `old` is `null` until a first write) or `slowMotion` (`Set Slow Motion`; recorded only, it moves no readable value). | ## JSON form diff --git a/probes/p8-slow-motion-wait/capture-2.txt b/probes/p8-slow-motion-wait/capture-2.txt new file mode 100644 index 0000000..7d3524c --- /dev/null +++ b/probes/p8-slow-motion-wait/capture-2.txt @@ -0,0 +1,37 @@ +[00:00:03] P8m f=100 i=0 t_ms=16.00 +[00:00:03] P8m f=100 i=1 t_ms=32.00 +[00:00:03] P8m f=100 i=2 t_ms=48.00 +[00:00:03] P8m f=100 i=3 t_ms=64.00 +[00:00:03] P8m f=100 i=4 t_ms=80.00 +[00:00:03] P8m f=100 i=5 t_ms=96.00 +[00:00:03] P8m f=100 i=6 t_ms=112.00 +[00:00:03] P8m f=100 i=7 t_ms=128.00 +[00:00:04] P8w f=100 wait_ms=16 elapsed_ms=16.00 +[00:00:04] P8w f=100 wait_ms=100 elapsed_ms=112.00 +[00:00:04] P8w f=100 wait_ms=500 elapsed_ms=512.00 +[00:00:05] P8w f=100 wait_ms=1000 elapsed_ms=1008.00 +[00:00:06] P8m f=50 i=0 t_ms=16.00 +[00:00:06] P8m f=50 i=1 t_ms=32.00 +[00:00:06] P8m f=50 i=2 t_ms=48.00 +[00:00:06] P8m f=50 i=3 t_ms=64.00 +[00:00:06] P8m f=50 i=4 t_ms=80.00 +[00:00:06] P8m f=50 i=5 t_ms=96.00 +[00:00:06] P8m f=50 i=6 t_ms=112.00 +[00:00:06] P8m f=50 i=7 t_ms=128.00 +[00:00:06] P8w f=50 wait_ms=16 elapsed_ms=16.00 +[00:00:06] P8w f=50 wait_ms=100 elapsed_ms=112.00 +[00:00:07] P8w f=50 wait_ms=500 elapsed_ms=512.00 +[00:00:08] P8w f=50 wait_ms=1000 elapsed_ms=1008.00 +[00:00:08] P8m f=90 i=0 t_ms=16.00 +[00:00:08] P8m f=90 i=1 t_ms=32.00 +[00:00:08] P8m f=90 i=2 t_ms=48.00 +[00:00:08] P8m f=90 i=3 t_ms=64.00 +[00:00:08] P8m f=90 i=4 t_ms=80.00 +[00:00:08] P8m f=90 i=5 t_ms=96.00 +[00:00:08] P8m f=90 i=6 t_ms=112.00 +[00:00:09] P8m f=90 i=7 t_ms=128.00 +[00:00:09] P8w f=90 wait_ms=16 elapsed_ms=16.00 +[00:00:09] P8w f=90 wait_ms=100 elapsed_ms=112.00 +[00:00:10] P8w f=90 wait_ms=500 elapsed_ms=512.00 +[00:00:11] P8w f=90 wait_ms=1000 elapsed_ms=1008.00 +[00:00:11] P8 done diff --git a/probes/p8-slow-motion-wait/capture-3.txt b/probes/p8-slow-motion-wait/capture-3.txt new file mode 100644 index 0000000..7d3524c --- /dev/null +++ b/probes/p8-slow-motion-wait/capture-3.txt @@ -0,0 +1,37 @@ +[00:00:03] P8m f=100 i=0 t_ms=16.00 +[00:00:03] P8m f=100 i=1 t_ms=32.00 +[00:00:03] P8m f=100 i=2 t_ms=48.00 +[00:00:03] P8m f=100 i=3 t_ms=64.00 +[00:00:03] P8m f=100 i=4 t_ms=80.00 +[00:00:03] P8m f=100 i=5 t_ms=96.00 +[00:00:03] P8m f=100 i=6 t_ms=112.00 +[00:00:03] P8m f=100 i=7 t_ms=128.00 +[00:00:04] P8w f=100 wait_ms=16 elapsed_ms=16.00 +[00:00:04] P8w f=100 wait_ms=100 elapsed_ms=112.00 +[00:00:04] P8w f=100 wait_ms=500 elapsed_ms=512.00 +[00:00:05] P8w f=100 wait_ms=1000 elapsed_ms=1008.00 +[00:00:06] P8m f=50 i=0 t_ms=16.00 +[00:00:06] P8m f=50 i=1 t_ms=32.00 +[00:00:06] P8m f=50 i=2 t_ms=48.00 +[00:00:06] P8m f=50 i=3 t_ms=64.00 +[00:00:06] P8m f=50 i=4 t_ms=80.00 +[00:00:06] P8m f=50 i=5 t_ms=96.00 +[00:00:06] P8m f=50 i=6 t_ms=112.00 +[00:00:06] P8m f=50 i=7 t_ms=128.00 +[00:00:06] P8w f=50 wait_ms=16 elapsed_ms=16.00 +[00:00:06] P8w f=50 wait_ms=100 elapsed_ms=112.00 +[00:00:07] P8w f=50 wait_ms=500 elapsed_ms=512.00 +[00:00:08] P8w f=50 wait_ms=1000 elapsed_ms=1008.00 +[00:00:08] P8m f=90 i=0 t_ms=16.00 +[00:00:08] P8m f=90 i=1 t_ms=32.00 +[00:00:08] P8m f=90 i=2 t_ms=48.00 +[00:00:08] P8m f=90 i=3 t_ms=64.00 +[00:00:08] P8m f=90 i=4 t_ms=80.00 +[00:00:08] P8m f=90 i=5 t_ms=96.00 +[00:00:08] P8m f=90 i=6 t_ms=112.00 +[00:00:09] P8m f=90 i=7 t_ms=128.00 +[00:00:09] P8w f=90 wait_ms=16 elapsed_ms=16.00 +[00:00:09] P8w f=90 wait_ms=100 elapsed_ms=112.00 +[00:00:10] P8w f=90 wait_ms=500 elapsed_ms=512.00 +[00:00:11] P8w f=90 wait_ms=1000 elapsed_ms=1008.00 +[00:00:11] P8 done diff --git a/probes/p8-slow-motion-wait/capture.json b/probes/p8-slow-motion-wait/capture.json index 18efab8..6d093f4 100644 --- a/probes/p8-slow-motion-wait/capture.json +++ b/probes/p8-slow-motion-wait/capture.json @@ -1,15 +1,95 @@ { "probe": "p8-slow-motion-wait", "client": { - "version": "", - "date": "", + "version": "2.25.0.1 - 154504.1", + "date": "2026-11-03", "locale": "zh-CN" }, - "runs": 0, + "runs": 3, "probe_sha256": "e369040ef4ebb0001975808ef05ae8287a8c21da720585b233bfe792f7898ce5", "hypothesis": "under Set Slow Motion(f) the tick still paces rule evaluation and Total Time Elapsed advances 16*f/100 ms per tick (P8m lines: 8, 14.4 and 16 ms at f=50, 90, 100), and Wait seconds map to ticks in that scaled time, so rounding still rounds up to a whole tick (P8w lines: elapsed_ms is the requested ms rounded up to a multiple of the scaled tick). The f=100 control repeats the P1 readings.", - "observed": [], - "result": "inconclusive", - "notes": "No captures yet; running the probe in the client is an owner step. The expected lines are hypotheses in expect.json. P8 is the one probe that calls Set Slow Motion itself; it must be the only rule loaded and it restores the factor to 100 at the end. If the log lines alone show the f=100 values at every factor, the [hh:mm:ss] timestamps decide whether the tick itself stretched (Wait(1) then takes about 2 s of wall time at f=50) or slow motion never reached the scheduler; the two readings print the same numbers.", - "sources": [] + "observed": [ + { + "factor": 100, + "metronome_t_ms": [ + 16, + 32, + 48, + 64, + 80, + 96, + 112, + 128 + ], + "wait_requested_ms": [ + 16, + 100, + 500, + 1000 + ], + "wait_elapsed_ms": [ + 16, + 112, + 512, + 1008 + ] + }, + { + "factor": 50, + "metronome_t_ms": [ + 16, + 32, + 48, + 64, + 80, + 96, + 112, + 128 + ], + "wait_requested_ms": [ + 16, + 100, + 500, + 1000 + ], + "wait_elapsed_ms": [ + 16, + 112, + 512, + 1008 + ] + }, + { + "factor": 90, + "metronome_t_ms": [ + 16, + 32, + 48, + 64, + 80, + 96, + 112, + 128 + ], + "wait_requested_ms": [ + 16, + 100, + 500, + 1000 + ], + "wait_elapsed_ms": [ + 16, + 112, + 512, + 1008 + ] + } + ], + "result": "mismatch", + "notes": "Three complete captures agree and disagree with the scaled-tick hypothesis. The client version was read on 2026-11-03. One separate attempt was discarded after an accidental character input. Inspector timestamps have one-second precision and do not independently measure wall time. Raw ASCII logs were received through UU Remote file transfer; the active log appeared empty until the game restarted. The game visibly slowed under factors 50 and 90 by eye, while the Inspector readings stayed identical to f=100; a rule cannot observe the factor. The cause is not measured: it may be a scaled simulation including the Inspector clock, or a game-world-only slowdown. P8 reads game time only, and the wall-clock ratio needs an external timer.", + "sources": [ + "Log-2026-11-03-02-06-04.txt", + "Log-2026-11-03-02-09-16.txt", + "Log-2026-11-03-02-24-39.txt" + ] } diff --git a/probes/p8-slow-motion-wait/capture.txt b/probes/p8-slow-motion-wait/capture.txt new file mode 100644 index 0000000..7d3524c --- /dev/null +++ b/probes/p8-slow-motion-wait/capture.txt @@ -0,0 +1,37 @@ +[00:00:03] P8m f=100 i=0 t_ms=16.00 +[00:00:03] P8m f=100 i=1 t_ms=32.00 +[00:00:03] P8m f=100 i=2 t_ms=48.00 +[00:00:03] P8m f=100 i=3 t_ms=64.00 +[00:00:03] P8m f=100 i=4 t_ms=80.00 +[00:00:03] P8m f=100 i=5 t_ms=96.00 +[00:00:03] P8m f=100 i=6 t_ms=112.00 +[00:00:03] P8m f=100 i=7 t_ms=128.00 +[00:00:04] P8w f=100 wait_ms=16 elapsed_ms=16.00 +[00:00:04] P8w f=100 wait_ms=100 elapsed_ms=112.00 +[00:00:04] P8w f=100 wait_ms=500 elapsed_ms=512.00 +[00:00:05] P8w f=100 wait_ms=1000 elapsed_ms=1008.00 +[00:00:06] P8m f=50 i=0 t_ms=16.00 +[00:00:06] P8m f=50 i=1 t_ms=32.00 +[00:00:06] P8m f=50 i=2 t_ms=48.00 +[00:00:06] P8m f=50 i=3 t_ms=64.00 +[00:00:06] P8m f=50 i=4 t_ms=80.00 +[00:00:06] P8m f=50 i=5 t_ms=96.00 +[00:00:06] P8m f=50 i=6 t_ms=112.00 +[00:00:06] P8m f=50 i=7 t_ms=128.00 +[00:00:06] P8w f=50 wait_ms=16 elapsed_ms=16.00 +[00:00:06] P8w f=50 wait_ms=100 elapsed_ms=112.00 +[00:00:07] P8w f=50 wait_ms=500 elapsed_ms=512.00 +[00:00:08] P8w f=50 wait_ms=1000 elapsed_ms=1008.00 +[00:00:08] P8m f=90 i=0 t_ms=16.00 +[00:00:08] P8m f=90 i=1 t_ms=32.00 +[00:00:08] P8m f=90 i=2 t_ms=48.00 +[00:00:08] P8m f=90 i=3 t_ms=64.00 +[00:00:08] P8m f=90 i=4 t_ms=80.00 +[00:00:08] P8m f=90 i=5 t_ms=96.00 +[00:00:08] P8m f=90 i=6 t_ms=112.00 +[00:00:09] P8m f=90 i=7 t_ms=128.00 +[00:00:09] P8w f=90 wait_ms=16 elapsed_ms=16.00 +[00:00:09] P8w f=90 wait_ms=100 elapsed_ms=112.00 +[00:00:10] P8w f=90 wait_ms=500 elapsed_ms=512.00 +[00:00:11] P8w f=90 wait_ms=1000 elapsed_ms=1008.00 +[00:00:11] P8 done