Skip to content

Commit 5fd6ab7

Browse files
author
Jacob Weinhold
committed
fix(capture): pass the measured 800ms CSRC inactivity window from the composition root
The sensor's own default is 400ms - chosen to span a packet gap, not a speech pause. Measured entry-timestamp staleness during real pauses is p50 550ms, so the MEDIAN natural pause already trips a synthesized deactivation and one speech phase fragments. Re-measured against the current channelizer (5 x 30 min seeded tapes): 400ms gives 1.67 lane activations per real turn, 800ms gives 1.13 - the knee - for 1.8pp more contamination; 1600ms starts merging turns. The value ships as a PARAMETER at the composition root, not as a forked constant in the sensor: the sensor already exposes `inactiveMs`, and a forked copy of its file is exactly how this measurement was lost once before downstream. Overridable via VEXA_CSRC_INACTIVE_MS where the bot process env is operator-controlled; an override that was SET but is unusable (empty, NaN, below one 100ms poll, above 10s) warns and falls back to the measured default - a NaN window would make both of the sensor's comparisons false and re-deactivate every source on every poll, the exact fragmentation this value exists to end, worse and silent. Scope: fragmentation only - no value of inactiveMs/lookbackMs/ flickerHoldMs brings lane contamination into a usable range (see TEAMS_CSRC_CONTESTED_TRANSCRIPTS.md). Measured and hardened downstream in Philflow/RavenBot (their #150, #162) and ported here against the same seams. Closes #1383 Signed-off-by: Jacob Weinhold <jacob@philflow.io>
1 parent 3f5c3c0 commit 5fd6ab7

4 files changed

Lines changed: 189 additions & 7 deletions

File tree

core/meetings/modules/mixed-capture-core/src/csrc-poll.test.ts

Lines changed: 32 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,11 @@ const receiver = (sources: () => ContributingSourceLike[]) => ({
8585
check('past inactiveMs the deactivation is SYNTHESIZED (the transport never sends this edge)',
8686
out.length === 2 && out[1].active === false && out[1].csrc === 7 && out[1].tMs === t,
8787
JSON.stringify(out));
88-
check('the default inactivity window is 400ms', CSRC_INACTIVE_MS === 400);
88+
// The module's own default spans a PACKET gap (jitter, DTX), not a speech PAUSE. It is only a
89+
// default: the measured production window is longer and is passed in by the composition root
90+
// (#1383), so what this file owns is the SEAM, not the number production runs on.
91+
check('the built-in window is the packet-gap default, and nothing more than a default',
92+
CSRC_INACTIVE_MS === 400, String(CSRC_INACTIVE_MS));
8993

9094
// Speaking again is a NEW activation — turns are edges, not a level.
9195
speaking = true; lastSpoke = t; poll.poll();
@@ -100,6 +104,33 @@ const receiver = (sources: () => ContributingSourceLike[]) => ({
100104
check('a poll after destroy() emits nothing', out.length === after);
101105
}
102106

107+
// ── the inactivity window is a PARAMETER, not a constant ─────────────────────────────────
108+
// A caller with a MEASURED window must be able to hand it over instead of forking this file. That
109+
// seam is what #1383 turns on: a second fork is how the measured 800 ms was lost the first time.
110+
{
111+
let t = 1_900_000_000_000;
112+
const out: CsrcTransition[] = [];
113+
let speaking = true;
114+
let lastSpoke = t;
115+
const poll = createCsrcPoll({
116+
onTransition: (x) => out.push(x),
117+
now: () => t,
118+
timeOrigin: () => 0,
119+
inactiveMs: 800,
120+
receivers: () => [receiver(() => [{ source: 9, timestamp: speaking ? t : lastSpoke, audioLevel: 0.4 }])],
121+
});
122+
poll.poll();
123+
check('override: the source opens a turn', out.length === 1 && out[0].active === true, JSON.stringify(out));
124+
speaking = false;
125+
t += 500; poll.poll();
126+
check('override: 500ms of silence — past the 400ms default, inside the caller\'s 800ms — holds the turn OPEN',
127+
out.length === 1, JSON.stringify(out));
128+
t += 400; poll.poll(); // 900ms > 800ms
129+
check('override: past the caller\'s window the deactivation is synthesized',
130+
out.length === 2 && out[1].active === false, JSON.stringify(out));
131+
poll.destroy();
132+
}
133+
103134
// ── two concurrent sources ──────────────────────────────────────────────────────────────────────
104135
{
105136
let t = 1_900_000_000_000;

core/meetings/services/bot/src/capture-bridge.ts

Lines changed: 47 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -381,6 +381,46 @@ const TEAMS_ENABLE_CAPTIONS = process.env.VEXA_TEAMS_ENABLE_CAPTIONS === '1';
381381
/** How many times to try the menu path before giving up (each attempt is ~3 s of UI waits). */
382382
const TEAMS_ENABLE_CAPTIONS_ATTEMPTS = Math.max(1, Number(process.env.VEXA_TEAMS_ENABLE_CAPTIONS_ATTEMPTS || 3));
383383

384+
/** The sensor's poll cadence (`CSRC_POLL_MS`). Not imported: this file must not pull the page-side
385+
* bundle into the Node build. Kept as the floor only, so a drift there is a slacker floor here,
386+
* never a wrong window. */
387+
const CSRC_MIN_INACTIVE_MS = 100;
388+
/** No plausible window is 10 s: the measurement below shows 1600 ms already merges distinct
389+
* turns, so a huge override is a typo wearing a number — the NaN failure mode again, silent. */
390+
const CSRC_MAX_INACTIVE_MS = 10_000;
391+
/**
392+
* The measured window (#1383) — how long the transport sensor holds a source active after its
393+
* last observed contribution. One name, so the fallback, the message and the default cannot drift.
394+
*
395+
* The sensor's own default is 400 ms (`CSRC_INACTIVE_MS` in @vexa/mixed-capture-core) — a value
396+
* chosen to span a packet gap. Measured against real speech it is too short to span a PAUSE:
397+
* entry-timestamp staleness during natural pauses came out at p50 550 ms, so the MEDIAN pause
398+
* already trips a synthesized deactivation and one speech phase fragments into splinters. Re-measured
399+
* against the current channelizer (5 × 30 min seeded tapes): 400 ms yields 1.67 lane activations per
400+
* real turn (67 % over-splitting), 800 ms yields 1.13 — the knee — for 1.8 pp more contamination;
401+
* 1600 ms starts merging distinct turns. So the production window is 800 ms.
402+
*
403+
* It lives HERE, at the composition root, and not as a forked constant in the sensor: the sensor
404+
* already exposes `inactiveMs` as a parameter, and forking its file a second time is exactly how
405+
* this value was lost once before (#1383). Overridable via VEXA_CSRC_INACTIVE_MS where the bot
406+
* process env is operator-controlled (the lite/process backend inherits the host env; the
407+
* container backends pass a closed env set — there the value rides the pod/profile spec).
408+
*/
409+
const CSRC_DEFAULT_INACTIVE_MS = 800;
410+
export function resolveCsrcInactiveMs(raw: string | undefined, warn: (m: string) => void = () => { /* silent */ }): number {
411+
// `undefined` is "no override", which is the normal case and silent. An override that was SET —
412+
// including an empty or blank one, which is what a half-finished deploy template looks like — is
413+
// an intent that could not be honoured, and gets said out loud.
414+
if (raw === undefined) return CSRC_DEFAULT_INACTIVE_MS;
415+
const n = Number(raw);
416+
if (!Number.isFinite(n) || n < CSRC_MIN_INACTIVE_MS || n > CSRC_MAX_INACTIVE_MS) {
417+
warn(`[bot] VEXA_CSRC_INACTIVE_MS=${JSON.stringify(raw)} is not a usable window (finite, ${CSRC_MIN_INACTIVE_MS}..${CSRC_MAX_INACTIVE_MS}ms) — using the measured ${CSRC_DEFAULT_INACTIVE_MS}ms`);
418+
return CSRC_DEFAULT_INACTIVE_MS;
419+
}
420+
return n;
421+
}
422+
const CSRC_INACTIVE_MS = resolveCsrcInactiveMs(process.env.VEXA_CSRC_INACTIVE_MS, (m) => console.warn(m));
423+
384424
/** Outcome of one enable attempt. `already-on` and `clicked` are successes; `failed` carries WHY,
385425
* because "captions never appeared" has two very different causes — the menu path changed, or the
386426
* tenant blocks captions — and only the reason distinguishes them on the first live run. */
@@ -796,7 +836,7 @@ export async function startCaptureBridge(
796836
// ── Start the page-side capture (VexaBrowserUtils preferred; production inline fallback). ──
797837
// The body of this callback runs IN THE BROWSER (Playwright serializes it); DOM globals are
798838
// reached via globalThis (this file type-checks against the Node lib — no DOM types here).
799-
await page.evaluate(async ({ isMixed, isPerTrack, isJitsi, isTeams, isZoom, botName, mainAudioGraceMs, mainAudioSilenceMs, mainAudioEnergyRms }) => {
839+
await page.evaluate(async ({ isMixed, isPerTrack, isJitsi, isTeams, isZoom, botName, mainAudioGraceMs, mainAudioSilenceMs, mainAudioEnergyRms, csrcInactiveMs }) => {
800840
const w = (globalThis as any) as Record<string, any>;
801841
if (isMixed) {
802842
// Zoom/Teams/Jitsi ride the WebRTC hook (installRemoteAudioHook, installed pre-nav), which mirrors
@@ -1159,6 +1199,9 @@ export async function startCaptureBridge(
11591199
w.logBot?.('[Csrc] observation ' + JSON.stringify(o));
11601200
w.__vexaObservation?.('csrc', o, Date.now());
11611201
},
1202+
// The MEASURED pause window, passed in rather than defaulted: the sensor's own 400 ms
1203+
// is shorter than the median natural speech pause (p50 550 ms) and fragments a turn.
1204+
inactiveMs: csrcInactiveMs,
11621205
log: (m: string) => w.logBot?.('[Csrc] ' + m),
11631206
});
11641207
} catch (e: any) {
@@ -1287,7 +1330,9 @@ export async function startCaptureBridge(
12871330
mainAudioGraceMs: Number(process.env.VEXA_TEAMS_MAIN_AUDIO_GRACE_MS || 15000),
12881331
// How long a PICKED mix may stay wholly silent before the lane abandons it for every track.
12891332
mainAudioSilenceMs: Number(process.env.VEXA_TEAMS_MAIN_AUDIO_SILENCE_MS || 20000),
1290-
mainAudioEnergyRms: Number(process.env.VEXA_TEAMS_MAIN_AUDIO_ENERGY_RMS || 0.006) }).catch((e) => {
1333+
mainAudioEnergyRms: Number(process.env.VEXA_TEAMS_MAIN_AUDIO_ENERGY_RMS || 0.006),
1334+
// The measured inactivity window (#1383) — a parameter the sensor accepts, never a fork of it.
1335+
csrcInactiveMs: CSRC_INACTIVE_MS }).catch((e) => {
12911336
console.error(`[bot] capture bridge: page-side start failed: ${String(e)}`); // L4: surfaces only on the VM
12921337
});
12931338

core/meetings/services/bot/src/csrc-wiring.test.ts

Lines changed: 103 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -24,13 +24,19 @@
2424
import { readFileSync, existsSync } from 'node:fs';
2525
import { fileURLToPath } from 'node:url';
2626
import path from 'node:path';
27-
import {
28-
startCaptureBridge, makeCsrcSink, makeObservationSink,
29-
type CsrcRecord, type CsrcCapableSink, type ObservationRecord, type ObservationCapableSink,
27+
import type {
28+
CsrcRecord, CsrcCapableSink, ObservationRecord, ObservationCapableSink,
3029
} from './capture-bridge.js';
3130
import type { Invocation } from './config.js';
3231
import type { BotPipeline } from './pipeline.js';
3332

33+
// HERMETIC: capture-bridge resolves VEXA_CSRC_INACTIVE_MS at module load, so an ambient override
34+
// in the developer's shell would fail the 800ms assertions below. Scrub BEFORE the module loads —
35+
// which is why this import is dynamic (a static one hoists above the delete).
36+
delete process.env.VEXA_CSRC_INACTIVE_MS;
37+
const { startCaptureBridge, makeCsrcSink, makeObservationSink, resolveCsrcInactiveMs } =
38+
await import('./capture-bridge.js');
39+
3440
let failed = 0;
3541
const check = (name: string, cond: boolean, detail?: string) => {
3642
console.log(` ${cond ? '✅' : '❌'} ${name}${cond || !detail ? '' : ` — ${detail}`}`);
@@ -87,10 +93,57 @@ const check = (name: string, cond: boolean, detail?: string) => {
8793
warnings.some((w) => w.includes('observation-clock-skew')) && stored[2].t >= t, warnings.join(' | '));
8894
}
8995

96+
// ── the window is resolved from env, and garbage never reaches the sensor ───────────────────────
97+
// The sensor resolves its option with `??`, which passes NaN through, and a NaN window makes BOTH
98+
// of its comparisons false: every source is re-deactivated on every poll — the fragmentation this
99+
// value exists to end, worse and silent. So an unusable override falls back rather than propagating.
100+
{
101+
check('window: no override ⇒ the measured 800ms', resolveCsrcInactiveMs(undefined) === 800,
102+
String(resolveCsrcInactiveMs(undefined)));
103+
check('window: a usable override wins', resolveCsrcInactiveMs('1200') === 1200,
104+
String(resolveCsrcInactiveMs('1200')));
105+
check('window: garbage falls back instead of becoming NaN',
106+
resolveCsrcInactiveMs('abc') === 800, String(resolveCsrcInactiveMs('abc')));
107+
check('window: zero, negative and empty fall back too — none of them is a window',
108+
resolveCsrcInactiveMs('0') === 800 && resolveCsrcInactiveMs('-5') === 800 && resolveCsrcInactiveMs('') === 800,
109+
`${resolveCsrcInactiveMs('0')}/${resolveCsrcInactiveMs('-5')}/${resolveCsrcInactiveMs('')}`);
110+
// A window shorter than one poll is stale before the next tick — the NaN failure mode wearing an
111+
// ordinary number. It is rejected at the floor, not accepted because it happens to be positive.
112+
check('window: shorter than one 100ms poll is rejected, one poll exactly is kept',
113+
resolveCsrcInactiveMs('1') === 800 && resolveCsrcInactiveMs('99') === 800 && resolveCsrcInactiveMs('100') === 100,
114+
`${resolveCsrcInactiveMs('1')}/${resolveCsrcInactiveMs('99')}/${resolveCsrcInactiveMs('100')}`);
115+
// The ceiling is the floor's mirror: a fat-fingered 600000 would hold every source active for
116+
// ten minutes and synthesize essentially no deactivations — the NaN failure mode wearing an
117+
// ordinary number, equally silent. 1600ms already merges turns; 10s is generous headroom.
118+
check('window: a huge override is rejected at the ceiling, ten seconds exactly is kept',
119+
resolveCsrcInactiveMs('600000') === 800 && resolveCsrcInactiveMs('10001') === 800
120+
&& resolveCsrcInactiveMs('10000') === 10000,
121+
`${resolveCsrcInactiveMs('600000')}/${resolveCsrcInactiveMs('10001')}/${resolveCsrcInactiveMs('10000')}`);
122+
{
123+
const warnings: string[] = [];
124+
const used = resolveCsrcInactiveMs('abc', (m) => warnings.push(m));
125+
check('window: a rejected override is SAID OUT LOUD, never silently ignored',
126+
used === 800 && warnings.length === 1 && warnings[0]!.includes('VEXA_CSRC_INACTIVE_MS="abc"'),
127+
JSON.stringify(warnings));
128+
const quiet: string[] = [];
129+
resolveCsrcInactiveMs(undefined, (m) => quiet.push(m));
130+
resolveCsrcInactiveMs('1200', (m) => quiet.push(m));
131+
check('window: no override and a good override are both silent — only a REJECTION warns',
132+
quiet.length === 0, JSON.stringify(quiet));
133+
// An empty override is what a half-rendered deploy template looks like. Treating it as "not
134+
// set" is how a knob gets ignored in silence — the exact failure the warning exists to prevent.
135+
const blank: string[] = [];
136+
check('window: an override SET to empty or blank warns too — it is an intent, not an absence',
137+
resolveCsrcInactiveMs('', (m) => blank.push(m)) === 800
138+
&& resolveCsrcInactiveMs(' ', (m) => blank.push(m)) === 800
139+
&& blank.length === 2, JSON.stringify(blank));
140+
}
141+
}
142+
90143
// ── The real bundle (built by build-browser-utils.mjs — turbo test depends on build) ─────────────
91144
const BUNDLE = path.resolve(path.dirname(fileURLToPath(import.meta.url)), '..', 'dist', 'browser-utils.global.js');
92145
if (!existsSync(BUNDLE)) {
93-
console.error(`❌ missing ${BUNDLE} — build the capture bundle first (pnpm --filter @vexa/bot build).`);
146+
console.error(`❌ missing ${BUNDLE} — build the capture bricks first (pnpm --filter @vexa/mixed-capture-core --filter @vexa/bot build).`);
94147
process.exit(1);
95148
}
96149

@@ -138,6 +191,19 @@ const utils = g.VexaBrowserUtils as Record<string, unknown> | undefined;
138191
check('bundle: window.VexaBrowserUtils.createCsrcPoll is exported (RED at base — brick not bundled)',
139192
typeof utils?.createCsrcPoll === 'function', `keys: ${Object.keys(utils ?? {}).join(',')}`);
140193

194+
// Capture the options the REAL bridge hands the REAL sensor factory. The window the production
195+
// path runs on is not observable from a transition alone (only from WHEN one is absent), and the
196+
// number itself is owned by the composition root, not by the sensor — so it is asserted here, on
197+
// the object that actually crosses. RED before #1383: the bridge passed no `inactiveMs` at all.
198+
type CsrcPollOpts = { inactiveMs?: number; pollMs?: number; now?: () => number; timeOrigin?: () => number;
199+
receivers?: () => unknown[]; onTransition: (t: { csrc: number; active: boolean; tMs: number }) => void };
200+
const realCreateCsrcPoll = utils!.createCsrcPoll as (o: CsrcPollOpts) => unknown;
201+
let productionCsrcOpts: CsrcPollOpts | undefined;
202+
(utils as Record<string, unknown>).createCsrcPoll = (o: CsrcPollOpts): unknown => {
203+
productionCsrcOpts = o;
204+
return realCreateCsrcPoll(o);
205+
};
206+
141207
// ── Fake Playwright Page + the Node seams ───────────────────────────────────────────────────────
142208
const page = {
143209
async exposeFunction(name: string, fn: unknown): Promise<void> { g[name] = fn; },
@@ -213,8 +279,41 @@ check('the spine and the stored sidecar agree on WHEN each edge happened',
213279
check('isolation: NO transition reached pipeline.recordHint — a csrc is an id, never a name',
214280
hints.length === 0, JSON.stringify(hints));
215281

282+
// ── the MEASURED inactivity window reaches the sensor (#1383) ────────────────────────────────────
283+
// 400 ms — the sensor's own default — is shorter than the median natural speech pause (measured
284+
// p50 550 ms), so a turn fragments into 1.67 lane activations. The composition root passes the
285+
// measured 800 ms instead. Asserted twice: the value that crossed, and what that value DOES.
286+
check('the bridge passes an explicit inactivity window to the sensor (RED at base: undefined)',
287+
productionCsrcOpts?.inactiveMs === 800, `inactiveMs=${String(productionCsrcOpts?.inactiveMs)}`);
288+
{
289+
// Re-drive the sensor over the PRODUCTION options object — same `inactiveMs`, with only the
290+
// clock and the receivers replaced, so the window is proven by behaviour and not by a number.
291+
let t = 1_900_000_000_000;
292+
const edges: Array<{ active: boolean }> = [];
293+
let speaking = true;
294+
let lastSpoke = t;
295+
const poll = realCreateCsrcPoll({
296+
...productionCsrcOpts!,
297+
onTransition: (x) => edges.push({ active: x.active }),
298+
now: () => t,
299+
timeOrigin: () => 0,
300+
receivers: () => [{ track: { kind: 'audio' },
301+
getContributingSources: () => [{ source: 5, timestamp: speaking ? t : lastSpoke, audioLevel: 0.4 }] }],
302+
}) as { poll(): void; destroy(): void };
303+
poll.poll();
304+
speaking = false;
305+
t += 500; poll.poll();
306+
check('a 500ms pause — past the sensor default, inside the measured window — does NOT close the turn',
307+
edges.length === 1 && edges[0].active === true, JSON.stringify(edges));
308+
t += 400; poll.poll();
309+
check('past the measured window the deactivation is synthesized',
310+
edges.length === 2 && edges[1].active === false, JSON.stringify(edges));
311+
poll.destroy();
312+
}
313+
216314
(g as any).setInterval = realSetInterval;
217315
(g as any).clearInterval = realClearInterval;
316+
(utils as Record<string, unknown>).createCsrcPoll = realCreateCsrcPoll;
218317
g.document = savedDocument;
219318

220319
if (failed) { console.error(`\n❌ csrc-wiring: ${failed} checks FAILED.`); process.exit(1); }
Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,7 @@
1+
- **Teams CSRC lanes stop fragmenting on natural speech pauses (#1383).** The transport sensor's
2+
400 ms inactivity window spans a packet gap, not a speech pause — the median pause (p50 ≈ 550 ms)
3+
already tripped a synthesized deactivation, splitting one speaker turn into ~1.7 lane activations.
4+
The composition root now passes the measured 800 ms window (the knee: 1.13 activations/turn),
5+
overridable via `VEXA_CSRC_INACTIVE_MS` where the bot process env is operator-controlled; an
6+
unusable override (empty, NaN, below one 100 ms poll, above 10 s) warns and falls back to the
7+
measured default instead of silently poisoning the sensor.

0 commit comments

Comments
 (0)