vwemirror/BT411
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

#32: RETRACT the retention diagnosis; count what matters (steals + true drops); name the saturating class

Browse Source 
The reopen said "the pool fills and never returns a source".  The 30s census in
the SAME field logs disproves it: free returns to ~227-230 between bursts and
reuses climbs ~20/s all session.  free=0 on the failure line is true by
DEFINITION at the instant of a failed acquire -- the third instance of the
counter-sampling trap (live=256-vs-6, then hsparm greps, now this), read off the
alarm line instead of the trend line.

WHAT THE LOGS ACTUALLY SHOW
  * The pool cycles; release-on-stop exists and works (the engine steal loop).
  * During firefights CONCURRENT demand exceeds 240 and the priority steal loop
    services each new sound by killing an old one -- continuously through
    combat (failures spread across every decile of every combat session).
  * Idle standing demand is ~13 sources.  My "each component holds its SourceSet
    to entity teardown, ~20-25 per mech" narrative was wrong.
  * The raw ACQUIRE FAILED line count (6.8k-19k per log) is NOISE: the steal
    loop retries after every failed attempt, so lines accumulate per EVENT and
    most events still play via a steal.  True drops were never counted.

CHANGES
  1. Census now carries steals= and drops= (drops = the steal loop ran dry and
     the sound NEVER played) plus a per-class drop histogram
     ("[audio] dropped by class: {class 1005 x4v: N} ...") -- all ungated, so
     the next field logs are decisive instead of suggestive.
  2. The ACQUIRE FAILED print is rate-limited to 1/30s and now names the
     requesting class + voice count.  19k-line log spam distorted this triage.
  3. BT_AUDIO_SOURCES=<n> now raises the POOL cap too (it previously raised the
     AL context budget while the pool stayed at 240, making the field
     experiment impossible to run).

MEASURED (9 mechs, missile autofire, 150s)
  * cap 240: peak 130 sources, 0 fails -- demand tracks SHOOTER count, not mech
    count; one shooter cannot saturate.  A 6-shooter lobby pins 240.
  * cap 48 (BT_AUDIO_SOURCES=64): saturation reproduced -- census
    steals=223 drops=455, histogram names the classes.
  * Dominant field requester (requested=4) = class 1005 Static3DPatchSource:
    world-placed effect sounds, i.e. EXPLOSIONS.  1001 DirectPatchSource x1v
    dominates drops at low cap; 1002 Dynamic3DPatchSource x3v present.

CONSEQUENCE FOR THE FIX ORDER: #84's stale-aim double detonation duplicates
exactly the saturating class on observer nodes.  Fix #84 FIRST, then re-read the
field census; only if it still saturates does the budget experiment
(BT_AUDIO_SOURCES with frame time measured) become the play.

KB: the wrong night-9 entry in open-questions.md replaced with the corrected
diagnosis; gotcha candidate noted -- an alarm-line counter is not a trend.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Joe DiPrima
2026-08-02 01:42:10 -05:00
co-authored by Claude Opus 5
parent 202ebbf84a
commit 3354db4bd1
3 changed files with 196 additions and 23 deletions
Download Patch File Download Diff File Expand all files Collapse all files
context/open-questions.md
+26 -11
View File
@@ -1034,17 +1034,32 @@ contributions already:
see — an authored record that resolves with no distinct behaviour to
reconstruct. Mike L. could confirm. (Gitea #104.)
**AUDIO SOURCE POOLING IS NOT FIXED — retention, not churn, is the wall** [T2].
The `#32` pooling change removed the per-sound `alGenSources`/`alDeleteSources`
churn (a real ~10% frame-time win) but every 693 field log still shows
`ACQUIRE FAILED (requested=4 live=240 pooled=240 free=0 ...)`
19,182 fails (Sauron) / 15,333 (Rajel) / 6,818 (Ronin), high-water **225 of 240**,
starting ~1% into the session. `free=0` is the diagnosis: the pool fills and never
returns a source. Each audio component reserves a SourceSet of up to 25 voices and
holds it to entity teardown, so peak demand scales with live audio COMPONENTS, not
audible sounds. A bigger cap only delays the wall. ⚠ Players reported audio as
"working fine" the same night — subjective impressions do not clear this class of
bug; read the log.
**AUDIO #32, CORRECTED DIAGNOSIS (2026-08-02): saturation during combat, NOT
retention** [T2 — census-measured]. An earlier version of this entry claimed the
pool "fills and never returns a source"; that was read off the FAILURE line, where
`free=0` is true by definition (a third instance of the counter-sampling trap).
The 30-second census in the same logs disproves it: `free` returns to ~227-230
between bursts and `reuses` climbs ~20/s all session — the pool cycles fine, and
release-on-stop exists and works (the engine's steal loop:
AudioSourceStop/SuspendMaintenance -> ReleaseChannels -> ReleaseSourceSet).
* The real regime: during firefights CONCURRENT demand exceeds the 240 cap and
the priority steal loop services each new sound by killing an old one,
thousands of times per combat session. Idle standing demand is only ~13.
* The raw `ACQUIRE FAILED` line count (6.8k-19k/log) is NOISE — the steal loop
retries after every failed attempt, so lines pile up per event and most
events still play via a steal. It is now rate-limited (1/30s) and the census
carries the true metrics: `steals=` and `drops=` (drops = the steal loop ran
dry and the sound NEVER played), plus a per-class drop histogram.
* The saturating requester is class 1005 = **Static3DPatchSource, 4 voices** —
world-placed effect sounds, i.e. EXPLOSIONS/impacts. Demand tracks the
number of SHOOTERS (9-mech one-shooter bench peaks at 130 with 0 fails; a
6-shooter field lobby pins 240). **#84's double detonation doubles exactly
this class on observer nodes** — fix #84 first, then re-read the field
census before touching the audio budget.
* `BT_AUDIO_SOURCES=<n>` now raises the POOL cap too, not just the AL context
budget (it previously did only the latter, making the experiment
impossible). If post-#84 logs still saturate, that is the field experiment
— with frame time measured, since more concurrent voices = more mixing CPU.
**Reading the missile impact line.** `[projectile] IMPACT damage=X ... burst=N`
prints X = **per missile**; the delivered total is `X * N`. A tester reading X
engine/MUNGA_L4/L4AUDRND.cpp
+139 -12
View File
@@ -1265,6 +1265,13 @@ Logical
source_result = audio_source->GetAudioChannelSet();
Check(source_result);
// #32 census: identify the requester while RequestAudioChannels runs, so a
// failure can be attributed to a component CLASS without threading an
// argument through the virtual (audio is main-thread only).
extern int gBTAudioReqClass, gBTAudioReqVoices;
gBTAudioReqClass = (int)audio_source->GetClassID();
gBTAudioReqVoices = audio_source->GetAudioVoiceCount();
resources_available =
RequestAudioChannels(
audio_source->GetAudioVoiceCount(),
@@ -1352,6 +1359,11 @@ Logical
// Else suspend the source
//--------------------------------------------------------------------
//
{ // #32 census: a steal ends a RUNNING sound early -- count it
// ungated so field logs show how hard the mixer is fighting.
extern long gBTAudioSteals;
++gBTAudioSteals;
}
if (
running_audio_source->GetAudioRenderType() ==
TransientAudioRenderType
@@ -1382,6 +1394,19 @@ Logical
iterator.Last();
running_audio_source = iterator.GetCurrent();
}
// #32 census: the steal loop is done and the request is STILL
// unsatisfied -- this sound is genuinely dropped. (The raw
// "ACQUIRE FAILED" print fires once per attempt INSIDE the steal loop,
// so its count wildly overstates real drops; this one does not.)
if (!resources_available)
{
extern long gBTAudioTrueDrops;
extern void BTAudioDropTally(int class_ID, int voices);
++gBTAudioTrueDrops;
BTAudioDropTally((int)audio_source->GetClassID(),
audio_source->GetAudioVoiceCount());
}
}
return resources_available;
}
@@ -1425,12 +1450,17 @@ Logical
if (now_ms - s_censusAt > 30000)
{
s_censusAt = now_ms;
extern long gBTAudioSteals, gBTAudioTrueDrops;
DEBUG_STREAM << "[audio] source census: live=" << gBTAudioSourcesLive
<< " pooled=" << BTAudioPoolSize()
<< " free=" << BTAudioPoolFree()
<< " reuses=" << BTAudioPoolReuses()
<< " acquireFails=" << gBTAudioAcquireFails
<< " steals=" << gBTAudioSteals
<< " drops=" << gBTAudioTrueDrops
<< std::endl << std::flush;
extern void BTAudioDropCensus();
BTAudioDropCensus();
}
}
@@ -1466,13 +1496,27 @@ Logical
if (!BTAudioPoolAcquire(&src))
{
++gBTAudioAcquireFails;
DEBUG_STREAM << "[audio] ACQUIRE FAILED (requested=" << requested
<< " live=" << gBTAudioSourcesLive
<< " pooled=" << BTAudioPoolSize()
<< " free=" << BTAudioPoolFree()
<< " fails=" << gBTAudioAcquireFails
<< ") -- the pool is exhausted; expect dropouts"
<< std::endl << std::flush;
// Rate-limited: the night-9 field logs carried 6.8k-19k of these per
// player, and the count is NOISE -- the steal loop retries after every
// failed attempt, so lines pile up per EVENT, and most events still
// end in a successful steal. One line per 30s band keeps the signal
// (the census carries the real counters: steals + true drops).
extern int gBTAudioReqClass, gBTAudioReqVoices;
static unsigned long s_failNoteAt = 0;
unsigned long fail_now = GetTickCount();
if (fail_now - s_failNoteAt > 30000)
{
s_failNoteAt = fail_now;
DEBUG_STREAM << "[audio] ACQUIRE FAILED (requested=" << requested
<< " reqClass=" << gBTAudioReqClass
<< " reqVoices=" << gBTAudioReqVoices
<< " live=" << gBTAudioSourcesLive
<< " pooled=" << BTAudioPoolSize()
<< " free=" << BTAudioPoolFree()
<< " fails=" << gBTAudioAcquireFails
<< ") -- saturated this instant; the steal loop decides what plays"
<< std::endl << std::flush;
}
return False;
}
source_request->sources[i] = src;
@@ -1557,6 +1601,62 @@ Logical
long gBTAudioSourcesLive = 0;
long gBTAudioAcquireFails = 0;
//
// #32 census v2. The night-9 field logs proved the FIRST generation of these
// counters mislead under pressure: "ACQUIRE FAILED ... free=0" reads as
// permanent retention, but free is 0 at the instant of any failed acquire BY
// DEFINITION -- the 30s census showed free back at ~230 between bursts, i.e.
// the pool cycles and the mixer is simply saturated DURING combat. (Same
// counter-sampling trap as the original live=256-vs-live=6, second offence.)
// These count what actually matters:
// gBTAudioSteals -- a running sound was ended early to service a new one
// gBTAudioTrueDrops -- the steal loop ran dry and the sound NEVER PLAYED
// plus a per-component-class tally of the dropped, so the next field log names
// the class that saturates the mixer instead of leaving it to inference.
//
int gBTAudioReqClass = -1;
int gBTAudioReqVoices = 0;
long gBTAudioSteals = 0;
long gBTAudioTrueDrops = 0;
struct BTAudioDropBin { int classID; int voices; long count; };
static BTAudioDropBin gBTAudioDropBins[12];
static int gBTAudioDropBinCount = 0;
void BTAudioDropTally(int class_ID, int voices)
{
for (int i = 0; i < gBTAudioDropBinCount; ++i)
{
if (gBTAudioDropBins[i].classID == class_ID
&& gBTAudioDropBins[i].voices == voices)
{
++gBTAudioDropBins[i].count;
return;
}
}
if (gBTAudioDropBinCount < 12)
{
gBTAudioDropBins[gBTAudioDropBinCount].classID = class_ID;
gBTAudioDropBins[gBTAudioDropBinCount].voices = voices;
gBTAudioDropBins[gBTAudioDropBinCount].count = 1;
++gBTAudioDropBinCount;
}
}
// One line under the 30s census, only when something was dropped since boot:
// which component classes lost sounds, and how many.
void BTAudioDropCensus()
{
if (gBTAudioDropBinCount == 0)
return;
DEBUG_STREAM << "[audio] dropped by class:";
for (int i = 0; i < gBTAudioDropBinCount; ++i)
DEBUG_STREAM << " {class " << gBTAudioDropBins[i].classID
<< " x" << gBTAudioDropBins[i].voices
<< "v: " << gBTAudioDropBins[i].count << "}";
DEBUG_STREAM << std::endl << std::flush;
}
//#############################################################################
// OpenAL SOURCE POOL (gitea #32)
//#############################################################################
@@ -1580,7 +1680,34 @@ long gBTAudioAcquireFails = 0;
// Not locked: the audio renderer runs on the main thread (only the network RX
// socket has its own). If that ever changes, this needs a mutex.
//
static const int kAudioPoolCap = 240; // just under OpenAL Soft's 256 default
// The pool's ceiling. DEFAULT: just under OpenAL Soft's 256-source context
// default. BT_AUDIO_SOURCES=<n> raises the AL context budget at Initialize
// (above); the pool cap now FOLLOWS it -- before this, the env raised the
// context and the pool still stopped at 240, so the experiment was impossible
// to run in the field. kAudioPoolMax bounds the static free-list array.
static const int kAudioPoolMax = 1024;
static int kAudioPoolCap = 240;
static int BTAudioPoolCapResolve()
{
static int s_done = 0;
if (!s_done)
{
s_done = 1;
const char *sv = getenv("BT_AUDIO_SOURCES");
if (sv != 0)
{
int n = atoi(sv);
if (n >= 64 && n <= 4096)
{
// stay under the context grant with a small reserve
kAudioPoolCap = (n - 16 < kAudioPoolMax) ? (n - 16) : kAudioPoolMax;
DEBUG_STREAM << "[audio] source pool cap follows BT_AUDIO_SOURCES: "
<< kAudioPoolCap << std::endl << std::flush;
}
}
}
return kAudioPoolCap;
}
//
// PEAK DEMAND is set by how many audio COMPONENTS are alive, not by how many
// sounds are audible: each component reserves a SourceSet of up to
@@ -1592,7 +1719,7 @@ static const int kAudioPoolCap = 240; // just under OpenAL Soft's 256 default
// sources than the cap -- alGenSources failing simply ends growth and the pool
// recycles what it has.
static ALuint gAudioPoolFree[kAudioPoolCap];
static ALuint gAudioPoolFree[kAudioPoolMax];
static int gAudioPoolFreeCount = 0; // entries in gAudioPoolFree
static int gAudioPoolTotal = 0; // sources ever generated (<= cap)
static long gAudioPoolReuses = 0; // diagnostics
@@ -1643,7 +1770,7 @@ Logical
--gAudioPoolTotal; // stale name: forget it
}
if (gAudioPoolTotal >= kAudioPoolCap)
if (gAudioPoolTotal >= BTAudioPoolCapResolve())
return False;
ALuint src = 0;
@@ -1678,12 +1805,12 @@ void
if (!alIsSource(src))
return;
BTAudioScrubSource(src);
if (gAudioPoolFreeCount < kAudioPoolCap)
if (gAudioPoolFreeCount < kAudioPoolMax)
{
gAudioPoolFree[gAudioPoolFreeCount++] = src;
return;
}
alDeleteSources(1, &src); // cannot happen (cap == array size)
alDeleteSources(1, &src); // cannot happen (max == array size)
--gAudioPoolTotal;
--gBTAudioSourcesLive;
}
scratchpad/night9/audioburst.sh
+31
View File
@@ -0,0 +1,31 @@
#!/usr/bin/env bash
# #32 v2: reproduce the FIELD regime -- mixer saturated during combat -- and
# name the class that saturates it. 9 mech entities (player + 8 dummies),
# missile autofire for maximum explosion density.
# $1 tag for the log
# $2 optional BT_AUDIO_SOURCES override (empty = default 240 cap)
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
sed "s/^map=.*/map=grass/; s/^time=.*/time=day/" MP.EGG > AUD.EGG
TAG="${1:-cap240}"
LOG=audioburst_$TAG.log
rm -f "$LOG"
export BT_SPAWN_ENEMY=8
export BT_AUTOFIRE=1 BT_AF_MISSILE=1 BT_AF_PERIOD=1
export BT_GOTO=enemy BT_GOTO_STOP=60
[ -n "$2" ] && export BT_AUDIO_SOURCES="$2" || unset BT_AUDIO_SOURCES
bt_launch "$LOG" AUD.EGG 0x03
sleep 150
taskkill //F //IM btl4.exe > /dev/null 2>&1
sleep 2
echo "=== census tail ==="
grep -oE "\[audio\] source census[^\n]*" "$LOG" | tail -4
echo "=== drop census ==="
grep -oE "\[audio\] dropped by class[^\n]*" "$LOG" | tail -2
echo "=== failure notes ==="
grep -cE "ACQUIRE FAILED" "$LOG"
echo "=== frame time ==="
grep -oE "\[rstat\][^\n]*avg=[0-9.]+ms" "$LOG" | tail -3