From a77c5a140796ca337e1a68b709a61e3866d58642 Mon Sep 17 00:00:00 2001 From: Joe DiPrima Date: Sun, 9 Aug 2026 16:46:10 -0500 Subject: [PATCH] #149: measure the filed suspect -- the #141 segment sweep is EXONERATED; ship [segperf] telemetry 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) Claude-Session: https://claude.ai/code/session_018SgmXGNMXavXiafKXf9MDC --- engine/MUNGA/JMOVER.cpp | 21 ++++++++++ engine/MUNGA_L4/L4VIDEO.cpp | 14 +++++++ game/reconstructed/mech4.cpp | 14 ++++++- scratchpad/night14/segperf.sh | 74 +++++++++++++++++++++++++++++++++++ 4 files changed, 122 insertions(+), 1 deletion(-) create mode 100644 scratchpad/night14/segperf.sh diff --git a/engine/MUNGA/JMOVER.cpp b/engine/MUNGA/JMOVER.cpp index ae2c912..5fad336 100644 --- a/engine/MUNGA/JMOVER.cpp +++ b/engine/MUNGA/JMOVER.cpp @@ -117,6 +117,16 @@ EntitySegment* } //~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ +// #149 perf telemetry (BT_PERF_LOG; counters cost two increments when unset). +// gBTSegWDirty counts the EXPENSIVE arm -- the mark-every-segment pass that +// invalidates the whole table -- separately from plain calls, because the #141 +// sweep put this accessor on per-frame weapon/beam paths and the open question +// is whether that multiplied the dirty-pass rate (each pass forces the next +// query of EVERY segment to re-derive its parent chain). +int gBTSegWCalls = 0; +int gBTSegWDirty = 0; +double gBTSegWMs = 0.0; + // void JointedMover::GetSegmentToWorld( @@ -125,6 +135,10 @@ void ) { Check(this); + static const int sPerf = getenv("BT_PERF_LOG") ? 1 : 0; + LARGE_INTEGER t0, t1, fq; + ++gBTSegWCalls; + if (sPerf) QueryPerformanceCounter(&t0); JointSubsystem *joints = GetJointSubsystem(); Check(joints); @@ -135,6 +149,7 @@ void // if (joints->AreJointsModified()) { + ++gBTSegWDirty; EntitySegment::SegmentTableIterator iterator(segmentTable); EntitySegment *current_segment; while( (current_segment = iterator.ReadAndNext() ) != NULL) @@ -153,6 +168,12 @@ void my_segment.GetSegmentToEntity(), localToWorld ); + if (sPerf) + { + QueryPerformanceCounter(&t1); + QueryPerformanceFrequency(&fq); + gBTSegWMs += 1000.0 * (double)(t1.QuadPart - t0.QuadPart) / (double)fq.QuadPart; + } Check_Fpu(); } diff --git a/engine/MUNGA_L4/L4VIDEO.cpp b/engine/MUNGA_L4/L4VIDEO.cpp index 4fd3a02..a8d118a 100644 --- a/engine/MUNGA_L4/L4VIDEO.cpp +++ b/engine/MUNGA_L4/L4VIDEO.cpp @@ -9034,6 +9034,20 @@ void DPLRenderer::ExecuteImplementation(RendererComplexity, RendererOrigin::Inte DEBUG_STREAM << "[rstat] frames=" << sFrames << " avg=" << (sAcc / sFrames) << "ms maxDraw=" << sMaxD << " maxPresent=" << sMaxP << " batches=" << gNumBatches << " culled=" << gBTNumCulled << "\n" << std::flush; + // #149: segment-refresh telemetry on the same cadence (BT_PERF_LOG). + // calls = GetSegmentToWorld entries; dirty = the mark-every-segment + // invalidation passes (the expensive arm the #141 sweep may have + // multiplied); ms = time inside the accessor for the whole window. + { + static const int sSegPerf = getenv("BT_PERF_LOG") ? 1 : 0; + extern int gBTSegWCalls, gBTSegWDirty; + extern double gBTSegWMs; + if (sSegPerf) + DEBUG_STREAM << "[segperf] calls=" << gBTSegWCalls + << " dirty=" << gBTSegWDirty + << " ms=" << gBTSegWMs << "\n" << std::flush; + gBTSegWCalls = 0; gBTSegWDirty = 0; gBTSegWMs = 0.0; + } sAcc = 0.0; sFrames = 0; sMaxD = 0.0; sMaxP = 0.0; } } diff --git a/game/reconstructed/mech4.cpp b/game/reconstructed/mech4.cpp index 6667676..222b880 100644 --- a/game/reconstructed/mech4.cpp +++ b/game/reconstructed/mech4.cpp @@ -9031,8 +9031,20 @@ void // This is the BEAM muzzle -- the same stale-cache exposure the // missile launch had, so a peer's beam would also originate // from the bind-pose gun port instead of the twisted torso. + // #149 A/B (BT_BEAM_SEGFRESH=0): revert THIS site to the + // pre-sweep plain compose, to measure whether the per-beam + // per-frame dirty-pass is the 857 draw-stall regression. + // This site runs inside the DRAW path per emitter per frame; + // the other swept sites are per-salvo/per-hit and cannot be + // a per-frame cost. Default = fresh (the swept behaviour). + static const int sBeamFresh = + !(getenv("BT_BEAM_SEGFRESH") && *getenv("BT_BEAM_SEGFRESH") == '0'); LinearMatrix mw; - GetSegmentToWorld(*s_portCache[energyOrdinal], &mw); + if (sBeamFresh) + GetSegmentToWorld(*s_portCache[energyOrdinal], &mw); + else + mw.Multiply(s_portCache[energyOrdinal]->GetSegmentToEntity(), + localToWorld); mz = mw; // Point3D = matrix translation } } diff --git a/scratchpad/night14/segperf.sh b/scratchpad/night14/segperf.sh new file mode 100644 index 0000000..a139461 --- /dev/null +++ b/scratchpad/night14/segperf.sh @@ -0,0 +1,74 @@ +#!/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= dirty= ms=