fix(timer): epoch headless timers from simulation_time, not wall clock

A mcrfpy.Timer stamped its epoch (last_ran) from GameEngine::runtime -- an
sf::Clock reading wall time -- at creation and every control method, while
GameEngine::step() ticks timers against simulation_time. The two clocks are
in unrelated frames, so a timer's FIRST fire under step() depended on
process-startup wall timing: headless replay was nondeterministic. Steady
state looked fine because the first fire re-stamps last_ran into the
simulation frame; only the first fire was contaminated.

Add a timer_now() helper that returns getSimulationTime() when headless and
runtime otherwise, and route all 9 epoch reads in PyTimer.cpp through it.
Windowed mode is unchanged; headless timers are now a pure function of the
step() sequence.

Surfaced by the #381 screenshot oracle: timer-driven snippets 048 and 191
rarely flipped their PNG. Post-fix both are byte-identical across 15 runs
and the full snippet oracle is 272/272 stable; suite 621/621.

Regression test asserts exact fire counts and callback runtimes across three
scenarios (interval boundaries, deterministic first fire, one-shot).

closes #383

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LTh2ZW7bd3XSd9qK86Z2CE
This commit is contained in:
John McCardle 2026-07-15 21:21:57 -04:00
commit a358ef4e4e
3 changed files with 99 additions and 9 deletions

File diff suppressed because one or more lines are too long

View file

@ -6,6 +6,20 @@
#include "McRFPy_Doc.h"
#include <sstream>
// #383: A timer's epoch must come from the SAME clock that ticks it. In headless mode
// that is GameEngine::simulation_time -- the deterministic clock step() advances
// explicitly -- NOT runtime, which is an sf::Clock reading wall time. step() tests
// timers against simulation_time; if a timer stamps its epoch from wall time, the two
// clocks are in unrelated frames and the first fire depends on process-startup timing,
// making headless replay nondeterministic. Windowed mode has no step() and keeps using
// runtime.
static int timer_now() {
if (!Resources::game) return 0;
return Resources::game->isHeadless()
? Resources::game->getSimulationTime()
: Resources::game->runtime.getElapsedTime().asMilliseconds();
}
PyObject* PyTimer::repr(PyObject* self) {
PyTimerObject* timer = (PyTimerObject*)self;
std::ostringstream oss;
@ -23,7 +37,7 @@ PyObject* PyTimer::repr(PyObject* self) {
// Get current time to show remaining
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
oss << " (remaining=" << timer->data->getRemaining(current_time) << "ms)";
} else if (timer->data->isActive()) {
@ -77,7 +91,7 @@ int PyTimer::init(PyTimerObject* self, PyObject* args, PyObject* kwds) {
// Get current time from game engine
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
// Create the timer with start parameter and name (#180)
@ -136,7 +150,7 @@ PyObject* PyTimer::start(PyTimerObject* self, PyObject* Py_UNUSED(ignored)) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
// If another timer has this name, stop it first
auto it = Resources::game->timers.find(self->name);
@ -177,7 +191,7 @@ PyObject* PyTimer::pause(PyTimerObject* self, PyObject* Py_UNUSED(ignored)) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
self->data->pause(current_time);
@ -192,7 +206,7 @@ PyObject* PyTimer::resume(PyTimerObject* self, PyObject* Py_UNUSED(ignored)) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
self->data->resume(current_time);
@ -207,7 +221,7 @@ PyObject* PyTimer::restart(PyTimerObject* self, PyObject* Py_UNUSED(ignored)) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
// Ensure timer is in engine map
auto it = Resources::game->timers.find(self->name);
@ -266,7 +280,7 @@ PyObject* PyTimer::get_remaining(PyTimerObject* self, void* closure) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
return PyLong_FromLong(self->data->getRemaining(current_time));
@ -307,7 +321,7 @@ int PyTimer::set_active(PyTimerObject* self, PyObject* value, void* closure) {
int current_time = 0;
if (Resources::game) {
current_time = Resources::game->runtime.getElapsedTime().asMilliseconds();
current_time = timer_now();
}
if (want_active) {

View file

@ -0,0 +1,76 @@
#!/usr/bin/env python3
"""
Regression test for #383: headless Timer epoch must come from simulation_time, not the
wall clock (runtime).
Before the fix, PyTimer stamped a timer's epoch from GameEngine::runtime (an sf::Clock,
wall time) while step() ticked timers against simulation_time. The two clocks are in
unrelated frames, so a timer's FIRST fire under step() depended on process-startup wall
timing -- headless replay was nondeterministic (it surfaced as rare byte-diffs in the
#381 snippet screenshots).
This test pins the deterministic contract: given a fixed sequence of step() calls, the
fire count and the exact callback runtimes are a pure function of simulation time.
Note simulation_time is a single clock that ACCUMULATES across the whole process -- it
does not reset between timers -- so expectations are tracked relative to a running clock
that mirrors the engine's `simulation_time += int(dt*1000)`.
Run: ./build/mcrogueface --headless --exec tests/regression/issue_383_..._test.py
"""
import sys
import mcrfpy
def fail(msg):
print(f"FAIL: {msg}")
sys.exit(1)
sim_ms = 0 # mirrors GameEngine::simulation_time
def step_ms(ms):
"""Advance the sim by an exact number of milliseconds, tracking the clock."""
global sim_ms
mcrfpy.step(ms / 1000.0)
sim_ms += ms
# --- Case 1: fires land exactly on simulation-time interval boundaries ----------------
# interval 100ms, stepped 50ms at a time for 400ms -> boundaries at epoch+100..epoch+400.
epoch1 = sim_ms
fires = []
mcrfpy.Timer("case1", lambda t, rt: fires.append(rt), 100)
for _ in range(8):
step_ms(50)
expected1 = [epoch1 + 100 * i for i in range(1, 5)]
if fires != expected1:
fail(f"case1: expected fires at {expected1}, got {fires}")
# --- Case 2: the FIRST fire is deterministic (the exact bug #383 exposed) -------------
# A 16ms timer created before its first step has epoch = current simulation_time, so the
# very next 16ms step fires it. Ten steps -> ten fires, one interval apart. Under the old
# wall-clock epoch the first fire could slip a step depending on startup timing.
epoch2 = sim_ms
fires2 = []
mcrfpy.Timer("case2", lambda t, rt: fires2.append(rt), 16)
for _ in range(10):
step_ms(16)
expected2 = [epoch2 + 16 * i for i in range(1, 11)]
if fires2 != expected2:
fail(f"case2: expected first-fire-deterministic {expected2}, got {fires2}")
# --- Case 3: one-shot timer fires exactly once and stops ------------------------------
epoch3 = sim_ms
fires3 = []
mcrfpy.Timer("case3", lambda t, rt: fires3.append(rt), 50, once=True)
for _ in range(6):
step_ms(50) # 300ms of stepping, well past the single 50ms fire
if fires3 != [epoch3 + 50]:
fail(f"case3: one-shot expected [{epoch3 + 50}], got {fires3}")
print("PASS: headless timer fires are deterministic on simulation_time (#383)")
sys.exit(0)