#148 is NOT A BUG: a peer mech does not tick before RunningMission -- by engine design
Chased to the bottom instead of stopping. The answer is that there was
nothing to fix, and my bench was lying to me.
Entity::Execute (ENTITY.cpp:556, real engine source [T0]) calls PerformAndWatch
ONLY when the app state is RunningMission/EndingMission or the entity
IsPreRunnable(); otherwise it merely WriteSimulationUpdate()s.
Entity::DefaultFlags is DynamicFlag|MasterInstance -- no PreRunFlag. Only
Player and Director add it, and Mech::Reset sets it for a reset MASTER ("a
reset master must tick"). A REPLICANT mech never gets it.
So a peer mech performs ZERO subsystem ticks until the round actually starts,
however much correctly-replicated data is arriving. Measured on the observer:
235 [perf-first] mech 3:161 master <- own mech, immediately
402 [torso-rec-rx] <- peer torso records arriving
2754 [perf-first] mech 2:55 REPLICANT <- peer's FIRST performance
2758 [torso] PushTwist COPY <- its torso ticks 4 lines later
2761 [ent-exec] state=5 <- RunningMission
The peer starts performing exactly at the RunningMission transition. That is
the engine doing what it says.
WHICH MEANS THE PREFIX WAS A BENCH ARTIFACT. BT_AUTOFIRE starts shooting
immediately, during WaitingForLaunch -- something no player can do in a real
match -- so those 60 leading salvos measured a peer whose torso had never run.
Every "ZZZZ...XXXX" pattern in this investigation was that, and the first X
lands within a few lines of the state transition. #141's fix is unaffected and
remains verified: the segment-cache defect was real and mid-match.
Chain of things ruled out on the way, all measured:
* record CADENCE is authentic -- sends on RATE CHANGE (payloads are the sweep
extremes, rate flips sign), peer dead-reckons between them. 12 records for
12 reversals is correct, not starved. My "only 13 records" premise was wrong.
* ComputeTargetTwist clamp -- limits load fine on the copy (+/-2.44346).
* the torso's own executable flag -- restoring the engine's instance branch
(f36f013) is a genuine fidelity fix but moved this by nothing.
* the replicant entity IS offered to the performer, executable=1, from line
171 -- 2500 lines before its first PerformAndWatch. The gate was inside
Execute, not the scheduler.
Adds [perf-first]: a ONE-SHOT per-mech receipt naming entity ID + instance at a
mech's first performance. Every other per-frame receipt in mech4 is anonymous,
which is precisely why this took so long in a 2-node log -- master and replicant
lines were indistinguishable. Name the mech.
Gotcha #29 records the bench-design rule this cost: judge a 2-node bench by
PREFIX vs INTERLEAVED, never by raw percentage, and check [ent-exec] state=
before suspecting replication. missileframe.sh carries the same warning.
#148 to be closed as not-a-bug.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_018SgmXGNMXavXiafKXf9MDC
This commit is contained in:
Joe DiPrima
co-authored by
Claude Opus 5
Claude Opus 5
parent
bb6605d53b
commit
cacca58836
@@ -916,3 +916,53 @@ Rules:
|
||||
and hid the copy's writes entirely. Sample **per instance-kind** whenever
|
||||
master and replicant objects share a diagnostic. (See also §gotcha on
|
||||
process-wide statics serving the player's data as the replicant's.)
|
||||
|
||||
## 29. A peer mech does NOT tick before RunningMission — bench-only, and it fakes a replication bug (#148, 2026-08-08)
|
||||
|
||||
`Entity::Execute` (`ENTITY.cpp:556`, real engine source [T0]) calls
|
||||
`PerformAndWatch` **only** when
|
||||
|
||||
```cpp
|
||||
application->GetApplicationState() == Application::RunningMission
|
||||
|| application->GetApplicationState() == Application::EndingMission
|
||||
|| IsPreRunnable()
|
||||
```
|
||||
|
||||
otherwise it just does `WriteSimulationUpdate`. `Entity::DefaultFlags` is
|
||||
`DynamicFlag|MasterInstance` — **no `PreRunFlag`**; only `Player` and `Director`
|
||||
add it in their DefaultFlags, and `Mech::Reset` sets it for a reset MASTER
|
||||
("a reset master must tick"). A **replicant mech never gets it.**
|
||||
|
||||
So during `LoadingMission` / `WaitingForLaunch` / `LaunchingMission` a peer mech
|
||||
performs **zero** subsystem ticks, no matter how much correctly-replicated data
|
||||
is arriving for it. Measured on the observer node:
|
||||
|
||||
```
|
||||
235 [perf-first] mech 3:161 master <- own mech, immediately
|
||||
402 [torso-rec-rx] <- peer's torso records start arriving
|
||||
2754 [perf-first] mech 2:55 REPLICANT <- peer's FIRST performance
|
||||
2758 [torso] PushTwist COPY <- its torso ticks 4 lines later
|
||||
2761 [ent-exec] state=5 <- RunningMission
|
||||
```
|
||||
|
||||
This is correct engine behaviour, **but it silently corrupts any bench that acts
|
||||
before the round starts.** `BT_AUTOFIRE`/`BT_GOTO` begin immediately, so early
|
||||
salvos measure a peer whose torso, gait and subsystems have never run — and the
|
||||
result reads exactly like a replication failure. It cost a full investigation
|
||||
(filed as #148) before the app-state trace showed the peer was simply not
|
||||
executing yet.
|
||||
|
||||
Rules:
|
||||
(a) **Judge a 2-node bench by PREFIX vs INTERLEAVED, never by raw percentage.**
|
||||
A clean leading run of failures that stops for good is almost always the
|
||||
pre-`RunningMission` window; interleaved failures are the real thing.
|
||||
(b) When a peer looks inert, check `[ent-exec] state=` before suspecting
|
||||
replication. States: `2` LoadingMission, `3` WaitingForLaunch,
|
||||
`4` LaunchingMission, `5` RunningMission.
|
||||
(c) Prefer benches that wait for `RunningMission` before acting — or slice the
|
||||
log at the transition — otherwise every peer-side metric carries this bias.
|
||||
(d) The receipts that make this legible: `BT_NET_TRACE` gives `[upd-repl]`
|
||||
(offered to the performer), `[ent-exec]` (state / preRun / instance) and
|
||||
`[perf-first]` (one-shot per mech: entity ID + instance at its FIRST
|
||||
performance). Anonymous per-frame receipts are useless in a 2-node log —
|
||||
**name the mech.**
|
||||
|
||||
@@ -2704,6 +2704,27 @@ volatile float gBTReplRenderYaw = -999.0f;
|
||||
void
|
||||
Mech::PerformAndWatch(const Time& till, MemoryStream *update_stream)
|
||||
{
|
||||
// #148 probe: one-shot per mech, the FIRST time this mech's per-frame
|
||||
// performance runs. Every other receipt in this file is anonymous, so
|
||||
// master and replicant lines are indistinguishable in a 2-node log -- which
|
||||
// is exactly what made the "when does the peer torso start ticking?" search
|
||||
// go in circles. Name the mech.
|
||||
if (getenv("BT_NET_TRACE"))
|
||||
{
|
||||
static const Mech *s_seen[16]; static int s_seenN = 0;
|
||||
int known = 0;
|
||||
for (int si = 0; si < s_seenN; ++si) if (s_seen[si] == this) { known = 1; break; }
|
||||
if (!known && s_seenN < 16)
|
||||
{
|
||||
s_seen[s_seenN++] = this;
|
||||
DEBUG_STREAM << "[perf-first] mech " << GetEntityID()
|
||||
<< " instance=" << (GetInstance() == Entity::ReplicantInstance
|
||||
? "REPLICANT" : "master")
|
||||
<< " this=" << (const void *)this
|
||||
<< " subsysCount=" << subsystemCount << "\n" << std::flush;
|
||||
}
|
||||
}
|
||||
|
||||
// Frame time slice from the simulation clock (same idiom as Mover::Perform).
|
||||
Scalar dt = till - lastPerformance;
|
||||
lastPerformance = till;
|
||||
|
||||
@@ -30,6 +30,22 @@
|
||||
# -- or B shows segResolved=0 (fell back to the body basis).
|
||||
# NOT REPRODUCED: both sides show the same twistDelta spread.
|
||||
#
|
||||
# ⚠ READ THE PREFIX, NOT THE PERCENTAGE (learned the hard way, 2026-08-08).
|
||||
# BT_AUTOFIRE starts shooting IMMEDIATELY, while the app is still in
|
||||
# WaitingForLaunch/LaunchingMission -- and Entity::Execute (ENTITY.cpp:556,
|
||||
# real engine source) only calls PerformAndWatch when the state is
|
||||
# RunningMission/EndingMission or the entity IsPreRunnable(). A REPLICANT mech
|
||||
# is not pre-runnable (Entity::DefaultFlags has no PreRunFlag; only Player /
|
||||
# Director add it, and Mech::Reset sets it for a reset MASTER), so a peer mech
|
||||
# does not tick at all until the round actually starts. Every salvo fired
|
||||
# before that reads twistDelta=0 legitimately -- the peer has no twist yet.
|
||||
# That is a BENCH artifact (nobody can fire pre-round in a real match), not a
|
||||
# defect: it showed up as a clean leading run of zeros, e.g.
|
||||
# ZZZZ...(60)...ZZZZXXXX...(105)...XXXX
|
||||
# and the first X lands within a few lines of the RunningMission transition.
|
||||
# So: judge this bench by whether the failures are a PREFIX (fine) or
|
||||
# INTERLEAVED (real), never by the raw percentage.
|
||||
#
|
||||
# Only A fires and only A sweeps its torso, so every REPLICANT line in B's
|
||||
# log is a mirror of an A salvo and the comparison is unambiguous.
|
||||
# =========================================================================
|
||||
|
||||
@@ -0,0 +1,105 @@
|
||||
#!/usr/bin/env bash
|
||||
# =========================================================================
|
||||
# #141 -- "missiles launch along the LEG/FOOT facing, then curve to the
|
||||
# target -- PEER POV ONLY" (Oracle, night 13: "the emitter is following the
|
||||
# foot facing"; shooter's own view correct).
|
||||
#
|
||||
# WHAT THE CODE SAYS SO FAR. Both sides already pass the mount segment:
|
||||
# MissileLauncher::FireWeapon (mislanch.cpp:363) and the REPLICANT salvo
|
||||
# mirror (mislanch.cpp:478) each hand BTPushProjectile
|
||||
# `GetSegmentIndex() /*task #67 mount frame*/`. BTPushProjectile then
|
||||
# rotates the authored MuzzleVelocity through
|
||||
# `seg->GetSegmentToEntity() * localToWorld` -- so the launch direction IS
|
||||
# the segment's world frame on BOTH nodes. Task #67 fixed exactly this
|
||||
# symptom once already, master-side ("missiles fire out of his back").
|
||||
#
|
||||
# So if the peer report is real, the difference is NOT which frame is asked
|
||||
# for -- it is whether the replicant's SEGMENT actually carries the torso
|
||||
# twist. Torso pushes currentTwist into the skeleton on both paths
|
||||
# (TorsoSimulation and TorsoCopySimulation both call UpdateJoints), so this
|
||||
# has to be measured, not reasoned about.
|
||||
#
|
||||
# THE MEASUREMENT. New [launchframe] receipt (BT_PROJ_LOG) prints, on both
|
||||
# nodes, the yaw of the launch forward vs the BODY forward:
|
||||
# [launchframe] master seg=N segResolved=1 segYaw=.. bodyYaw=.. twistDelta=..
|
||||
# [launchframe] REPLICANT seg=N segResolved=1 segYaw=.. bodyYaw=.. twistDelta=..
|
||||
# twistDelta is the torso twist expressed in the launch direction.
|
||||
#
|
||||
# BUG CONFIRMED: A (master) shows |twistDelta| sweeping well away from 0
|
||||
# while B (replicant mirror) stays pinned near 0
|
||||
# -- or B shows segResolved=0 (fell back to the body basis).
|
||||
# NOT REPRODUCED: both sides show the same twistDelta spread.
|
||||
#
|
||||
# Only A fires and only A sweeps its torso, so every REPLICANT line in B's
|
||||
# log is a mirror of an A salvo and the comparison is unambiguous.
|
||||
# =========================================================================
|
||||
set -x
|
||||
. /c/git/bt411/scratchpad/night6/bench_common.sh
|
||||
cd /c/git/bt411/content || exit 1
|
||||
taskkill //F //IM btl4.exe > /dev/null 2>&1
|
||||
sleep 2
|
||||
rm -f mf_a.log mf_b.log mf_relay.log
|
||||
bt_expert_egg MP.EGG MF.EGG
|
||||
sed -i "s/^map=.*/map=grass/; s/^time=.*/time=day/; s/^vehicle=.*/vehicle=madcat/" MF.EGG
|
||||
|
||||
# B: the OBSERVER. Drives at A so it stays in range, but does NOT fire and
|
||||
# does NOT sweep -- so every [launchframe] REPLICANT line in mf_b.log is a
|
||||
# mirror of one of A's salvos.
|
||||
( export BT_GOTO=enemy BT_GOTO_STOP=150
|
||||
export BT_PROJ_LOG=1 BT_MP_LOG=1 BT_TORSO_LOG=1 BT_NET_TRACE=1
|
||||
bt_launch mf_b.log MF.EGG 0x0C -net 1601 )
|
||||
sleep 2
|
||||
# A: the SHOOTER. Sweeps the torso hard so twistDelta is unmistakably
|
||||
# non-zero at fire time, and autofires missiles at the designated enemy.
|
||||
( export BT_GOTO=enemy BT_GOTO_STOP=150
|
||||
export BT_AUTOFIRE=1 BT_AF_MISSILE=1 BT_AF_PERIOD=7
|
||||
export BT_LOCK_SWEEP=0.35
|
||||
export BT_PROJ_LOG=1 BT_TORSO_LOG=1 BT_MP_LOG=1
|
||||
bt_launch mf_a.log MF.EGG 0x03 -net 1501 )
|
||||
sleep 5
|
||||
python ../tools/btconsole.py MF.EGG 127.0.0.1:1501 127.0.0.1:1601 > mf_relay.log 2>&1 &
|
||||
RELAY=$!
|
||||
sleep 170
|
||||
kill $RELAY 2>/dev/null
|
||||
sleep 3
|
||||
bt_kill_ours; sleep 2; taskkill //F //IM btl4.exe > /dev/null 2>&1; sleep 3
|
||||
|
||||
echo "=================== #141 MISSILE LAUNCH FRAME ==================="
|
||||
echo "--- did A fire, and did B mirror? ---"
|
||||
echo -n " A [launchframe] master lines ....... "; grep -ac "launchframe\] master" mf_a.log
|
||||
echo -n " B [launchframe] REPLICANT lines .... "; grep -ac "launchframe\] REPLICANT" mf_b.log
|
||||
echo
|
||||
echo "--- did the segment RESOLVE on each side? (segResolved=0 would be the bug) ---"
|
||||
echo -n " A segResolved=0 ... "; grep -a "launchframe\] master" mf_a.log | grep -ac "segResolved=0"
|
||||
echo -n " B segResolved=0 ... "; grep -a "launchframe\] REPLICANT" mf_b.log | grep -ac "segResolved=0"
|
||||
echo
|
||||
echo "--- THE COMPARISON: twistDelta spread on each side ---"
|
||||
python - <<'PY'
|
||||
import re, io
|
||||
def stats(path, tag):
|
||||
v = []
|
||||
try:
|
||||
for ln in io.open(path, encoding="latin-1", errors="replace"):
|
||||
if "[launchframe] " + tag in ln:
|
||||
m = re.search(r"twistDelta=([-\d.e+]+)", ln)
|
||||
if m:
|
||||
try: v.append(float(m.group(1)))
|
||||
except ValueError: pass
|
||||
except IOError:
|
||||
print(" %s: no log" % tag); return
|
||||
if not v:
|
||||
print(" %-9s no samples" % tag); return
|
||||
a = [abs(x) for x in v]
|
||||
big = sum(1 for x in a if x > 0.10) # ~5.7 deg -- clearly twisted
|
||||
print(" %-9s n=%-4d |twistDelta| max=%.4f mean=%.4f >0.10rad: %d (%.0f%%)"
|
||||
% (tag, len(v), max(a), sum(a)/len(a), big, 100.0*big/len(a)))
|
||||
stats(r"C:\git\bt411\content\mf_a.log", "master")
|
||||
stats(r"C:\git\bt411\content\mf_b.log", "REPLICANT")
|
||||
print()
|
||||
print(" VERDICT: master twisted + REPLICANT pinned near 0 => #141 CONFIRMED.")
|
||||
print(" both twisted alike => NOT reproduced.")
|
||||
PY
|
||||
echo
|
||||
echo "--- sample lines, both sides ---"
|
||||
grep -a "launchframe\] master" mf_a.log | head -4
|
||||
grep -a "launchframe\] REPLICANT" mf_b.log | head -4
|
||||
Reference in New Issue
Block a user