Repository navigation
test: give telemetry probes their subprocess budget - #120
JasonBuildAI wants to merge 1 commit into
Conversation
Each probe boots a fresh tsx process that captureRuntime already lets run for 15 s, but Vitest kills the test at its 5 s default first. Individually the probes take 3.2-4.3 s, so a full-suite run on a clean main checkout failed 2 of them with "Test timed out in 5000ms"; under this budget the suite is 302/302.
NathanTarbert
left a comment
There was a problem hiding this comment.
Thanks @JasonBuildAI, nice catch reading those two numbers side by side. With captureRuntime allowing each probe 15 seconds and Vitest stopping at 5, the outcome depends on how busy the machine is. Under load here, main came within a quarter second of the cap. Setting the file's timeout above the subprocess budget keeps a real hang reported by execFile rather than as a test timeout, which is the right way round.
Looks good to me.
Thanks Nathan, really appreciate the review — and for timing this on a clean main. Good to know it lands within a quarter second of the cap there too. |
What this changes
tests/telemetry.test.tswas timing out intermittently, and I think the causeis a mismatch between two numbers already in the file.
Seven of its eight tests each boot a fresh Node subprocess with
--import tsxto load
src/server/platform.ts, so that the SDK's telemetry singleton startsclean and observes one environment at a time.
captureRuntime()gives thatsubprocess a 15 s budget:
but Vitest ends the test itself after its 5 s default
testTimeout, and therepo doesn't raise that anywhere (no
testblock invite.config.ts). So asubprocess that is still comfortably inside the budget it was given gets cut
off by the test runner, and the failure is a bare
Test timed out in 5000ms.I set
testTimeoutto 20 s for this file only. The number is deliberatelylarger than the subprocess budget rather than equal to it: if a probe genuinely
hangs,
execFilestill trips first and reports that, instead of the testtimeout firing first on a merely slow start.
How I measured it
Run in isolation, all eight tests pass, but the margin over the 5 s cap is thin:
Run as part of the full suite, on an unmodified
maincheckout, two of themcross the line:
That's contention, not a wrong assertion: the tsx cold compile is slow on its
own, and 48 files are competing for the CPU at the same time. I also noticed
@Adii0906 ran into the same thing in #100 and mentioned "3 unrelated timeouts
remain in telemetry.test.ts", so I don't think it's my machine alone.
Honest scope: I could not reach the Actions API from here, so I can't say
whether CI on ubuntu is red right now. It may well pass on a fast runner today.
What I can say is that the tests run at roughly 65-85% of their allowed time,
which is not much headroom, and the file already budgets the subprocess 3x
longer than it budgets the test.
The change
One file, five added lines, no production code:
vialongsideexpectandit;vi.setConfig({ testTimeout: 20000 })at the top of the file;I first passed the timeout as an argument to each
it()call, but the longtest-name strings then push the calls past 80 columns and Prettier reflows the
whole blocks, which turns a 5-line change into a 74-line diff. Keeping it at
file scope via
vi.setConfigavoids that churn. The tests that only readcompose.ymlinherit the same budget and are unaffected; the two opt-outchecks still assert an empty capture, so a probe that quietly stops emitting
events would still fail for the right reason.
Verification
On Node 24, matching CI's
node-versionand the repo'senginesfield, withbranch = upstream/main + 1 commit(no rebase needed):npm run check-format- Prettier cleannpm run lint- cleannpm run typecheck- cleannpm test- 48 files, 302 tests passed (run twice, same result; was 2 failed | 300 passed on unmodifiedmain)npm run build- built successfullyThe probes still intercept
globalThis.fetchin the subprocess, so nothing heresends live telemetry or needs a network or an Intelligence connection.