A/B on identical 2-node beam-heavy runs (scratchpad/night14/segperf.sh),
BT_BEAM_SEGFRESH=1 (swept behaviour) vs =0 (pre-sweep compose at the beam
site, the only per-frame swept call):
fresh(swept) legacy(pre-sweep)
rstat blocks>50ms 0 0
maxDraw worst 730ms 646ms (mission-load spike, BOTH)
segperf dirty-passes 38/s 4/s <- the sweep DOES multiply
segperf accessor ms 0.97/s 0.57/s <- ...by 0.4 ms/s. Noise.
So the invalidation-storm hypothesis I filed on #149 is wrong by three orders
of magnitude, and Oracle's sustained 50-104ms stall window does NOT reproduce
on this rig at all. Refusing to guess a third time: the build now carries the
telemetry to answer it on the machine that actually regresses --
[segperf] calls= dirty= ms= printed beside every [rstat] window under
BT_PERF_LOG (JMOVER counters; two integer increments when unset), and
BT_BEAM_SEGFRESH=0 remains as a one-env A/B for the beam site.
Default stays FRESH (the swept accessor): its measured cost is trivial and it
is the correctness-cautious side while the peer-beam-staleness question is
unmeasured.
Next for #149: Oracle runs one session with BT_PERF_LOG=1. If [segperf] ms is
large inside his stalled windows, segment work is implicated on HIS
configuration and BT_BEAM_SEGFRESH=0 gives the immediate A/B; if it is small
(as here), the stall is elsewhere in the 817->857 delta and we hunt with his
numbers instead of my theories.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_018SgmXGNMXavXiafKXf9MDC
75 lines
3.3 KiB
Bash
75 lines
3.3 KiB
Bash
#!/usr/bin/env bash
|
|
# =========================================================================
|
|
# #149 -- 817 -> 857 stall regression (Oracle: 97 blocks >50ms, all in the
|
|
# mission-load window, maxDraw up to 518ms; zero such blocks on 817, same
|
|
# machine). My filed suspect was the #141 segment-cache sweep -- but that is
|
|
# a HYPOTHESIS, and #137 just taught us what plausible-but-unmeasured
|
|
# theories are worth. So: measure first.
|
|
#
|
|
# INSTRUMENTATION (this build):
|
|
# [segperf] calls=<GetSegmentToWorld entries> dirty=<mark-every-segment
|
|
# invalidation passes> ms=<time inside the accessor> -- per rstat window,
|
|
# BT_PERF_LOG-gated. The DIRTY count is the tell: if the beam path
|
|
# multiplies invalidations, dirty >> mechs-per-frame and ms tracks maxDraw.
|
|
#
|
|
# A/B: identical 2-node runs, beams firing continuously.
|
|
# run A: default (swept behaviour: beam muzzle via GetSegmentToWorld)
|
|
# run B: BT_BEAM_SEGFRESH=0 (pre-sweep plain compose at the BEAM site only)
|
|
# If A's stalls/dirty collapse in B, the beam-site sweep is the regression.
|
|
# If A == B and both are clean, the suspect is EXONERATED and the real 857
|
|
# load-stall cause is elsewhere (next: diff the load path).
|
|
# =========================================================================
|
|
set -x
|
|
. /c/git/bt411/scratchpad/night6/bench_common.sh
|
|
cd /c/git/bt411/content || exit 1
|
|
|
|
run_one () { # $1 = tag, $2 = extra env value for BT_BEAM_SEGFRESH
|
|
taskkill //F //IM btl4.exe > /dev/null 2>&1
|
|
sleep 2
|
|
rm -f sp_${1}_a.log sp_${1}_b.log sp_${1}_relay.log
|
|
bt_expert_egg MP.EGG SP.EGG
|
|
sed -i "s/^map=.*/map=grass/; s/^time=.*/time=day/; s/^vehicle=.*/vehicle=madcat/" SP.EGG
|
|
( export BT_GOTO=enemy BT_GOTO_STOP=120 BT_AUTOFIRE=1 BT_AF_PERIOD=3
|
|
export BT_MP_LOG=1
|
|
bt_launch sp_${1}_b.log SP.EGG 0x0C -net 1601 )
|
|
sleep 2
|
|
( export BT_GOTO=enemy BT_GOTO_STOP=120 BT_AUTOFIRE=1 BT_AF_PERIOD=3
|
|
export BT_PERF_LOG=1 BT_MP_LOG=1
|
|
export BT_BEAM_SEGFRESH=${2}
|
|
bt_launch sp_${1}_a.log SP.EGG 0x03 -net 1501 )
|
|
sleep 5
|
|
python ../tools/btconsole.py SP.EGG 127.0.0.1:1501 127.0.0.1:1601 > sp_${1}_relay.log 2>&1 &
|
|
local RELAY=$!
|
|
sleep 260
|
|
kill $RELAY 2>/dev/null
|
|
sleep 3
|
|
bt_kill_ours; sleep 2; taskkill //F //IM btl4.exe > /dev/null 2>&1; sleep 3
|
|
}
|
|
|
|
run_one fresh 1
|
|
run_one legacy 0
|
|
|
|
echo "=================== #149 SEGPERF A/B ==================="
|
|
for t in fresh legacy; do
|
|
echo "--- $t ---"
|
|
python - <<PY
|
|
import re, io
|
|
v=[]; seg=[]
|
|
for ln in io.open(r"C:\git\bt411\content\sp_${t}_a.log", encoding="latin-1", errors="replace"):
|
|
m=re.search(r"\[rstat\] frames=\d+ avg=([\d.]+)ms maxDraw=([\d.]+)", ln)
|
|
if m: v.append((float(m.group(1)), float(m.group(2))))
|
|
m=re.search(r"\[segperf\] calls=(\d+) dirty=(\d+) ms=([\d.]+)", ln)
|
|
if m: seg.append((int(m.group(1)), int(m.group(2)), float(m.group(3))))
|
|
if v:
|
|
import statistics
|
|
avgs=[a for a,_ in v]; draws=[d for _,d in v]
|
|
stall=sum(1 for a,_ in v if a>50)
|
|
print(" rstat blocks=%d avg-med=%.2fms maxDraw-med=%.2f maxDraw-worst=%.1f blocks>50ms=%d"
|
|
% (len(v), statistics.median(avgs), statistics.median(draws), max(draws), stall))
|
|
if seg:
|
|
c=[x[0] for x in seg]; d=[x[1] for x in seg]; ms=[x[2] for x in seg]
|
|
print(" segperf windows=%d calls-med=%d dirty-med=%d ms-med=%.2f ms-worst=%.2f"
|
|
% (len(seg), sorted(c)[len(c)//2], sorted(d)[len(d)//2], sorted(ms)[len(ms)//2], max(ms)))
|
|
PY
|
|
done
|