Repository navigation
test(chain): stop chain scenarios waiting on real time - #713
Conversation
TheGreatAxios
left a comment
There was a problem hiding this comment.
Independent review at be34a95. bun run lint, bun run check and the unit tests for triage-manager, triage-contracts and the hub's workflow-release pass (353). Chain scenarios were not run.
Production defaults match main for every wait that moved: ready 120000, start grace 120000, manager poll 30000, wake poll 2000, reconcile 300000, retry 15000, coalesce 30000, liveness 60000, stalled 300000. The deploy hold is still 2 * ready + 30000, and PASSES stays 720. A tree without timings falls back to the defaults. Nothing outside timingsFrom reads a TRIAGE_* timing.
Findings, most important first:
- A blank timing variable now crashes the hub at boot. On main,
loadHubEnvdrops blank values throughpresentValues("Blank values count as missing"), soTRIAGE_RECONCILE_INTERVAL_MS=ran on the default.timingsFromreadsprocess.envdirectly and throws on""," "and" 300000". I reproduced this withtimingsFrom({ TRIAGE_RECONCILE_INTERVAL_MS: "" }). The four variables that already existed (reconcile interval, coalesce quiet, liveness, stalled) changed behaviour this way. Separately,apps/hub/src/timings.tsreadsprocess.envwhen the module is imported, outsideloadHubEnv, so bad values no longer show up in its combined error and every test that importsmanager-state.tsreads the real environment. Suggested fix: read the timings from the envloadHubEnvhas already filtered and passTIMINGSin as a dependency, not as a module-level constant. - The PR closes CL-11645, but two of its outcomes are not met. (a) Hub tests still sleep in real time:
apps/hub/src/server.postgres.test.ts:688(Bun.sleep(5_000)) andapps/hub/src/github/lock-key.postgres.test.ts:34(1.5 s). The plan put the sleep check outside the chain harness, but the lint rule only coverstests/chain/. (b) The slowest shard is still over three minutes (1/5 at 211 s, 5/5 at 186 s). Either finish both or narrow the issue and keep it open. - Shard 5/5 regression (unverified hypothesis). It is not a layout change: main also ran
--parallel=2with pushed and always together (117 s total, now 163 s). It is not only two stacks sharing a runner either: sidecar-cap mostly ran alone after pushed finished and still went from 32 s to 48 s.pushed.test.tsandalways.test.tsdid not change, so the harness timings are the cause. The likeliest hot path isreconcileIntervalMs: 2_000.repo-activity.tstreats a repository with no webhook as quiet, so it is stale and listed again on every pass. That means all 12 chain repositories are listed every 2 s instead of every 15 s. A pushed repository is also relisted for 60 s of grace. The 1 s manager poll and 2 s liveness add to it. A 100 ms harness poll is unlikely to matter, since it now reuses one DB handle. To confirm, rerun shard 5 locally withreconcileIntervalMsback at 15000 and compare. - sidecar-cap raises only
managerReadyMs. Its start grace stays at 60 s while the listener waits 120 s. On main both values were one 2-minute window, andmanager-state.tsdescribes the grace as "the listener waits this long for a manager to start". Production now accepts settings where the grace is shorter than the ready window, with nothing to stop it. Either enforce grace >= ready the waytriageCoalesceWindowchecks its limit, or override both in sidecar-cap. The why comment on sidecar-cap itself is fine. - The lint rule only catches literal numbers. It works as described:
Bun.sleep(1_000)andsetTimeout(r, 2000)fail andBun.sleep(100)passes. It missesBun.sleep(SETTLE)with a named constant,Bun.sleep(2 * 1000), and the promisesetTimeout(5_000)fromnode:timers/promisesimported under another name. Keeping it out of the root config is justified: the root stays plain data for the code-review lint step. - unrouted lost its timing guarantee. With the reconcile interval at 60 min, only the retry or the pass when the listener starts can mail the head.
expect(msOf(sent)).toBeGreaterThanOrEqual(msOf(live))checks the order but not which path sent the mail, yet the test title says "by the short retry rather than the reconcile pass". Either assert the retry's log line or loosen the title. - Release republish on first deploy (informational).
withReleasenow always writesrelease.jsonwithtimingsfor chain workflows, so every listener and manager asset hash changes and every workspace rolls once on deploy. State this in the PR. - Nits.
- The
Publishedschema inpackages/triage-manager/src/release.tshardcodesgithub?andbitbucket-datacenter?where it could derive them fromREPO_SOURCES. - docs/DEV.md says the ping timeout is "the one real wait left", but unwoken still waits through two 60 s ready windows.
- docs/DEV.md repeats the AGENTS.md shard rule word for word.
- The
Confirmed fine:
- The AGENTS.md line is in place.
.env.exampleand SELF_HOST give one line per variable, with no hedges.TIMINGSintests/chain/stack.tsis documented.- local-sidecars is split into three tests, one cause each.
- woken waits on a counted
take, and unset readsneeds-setup. - Two signed Conventional Commits, no attribution.
be34a95 to
c73adb7
Compare
|
Replies to the review, fixed in c73adb7:
|
TheGreatAxios
left a comment
There was a problem hiding this comment.
Re-review at c73adb7. All eight items are addressed:
- The timings go back through
loadHubEnv. The new env test covers a blank value (keeps the default) and" 300000"and"abc"(both fail). - Boot calls
timingsFrom(env)once and passes it tosetTimings.apps/hub/src/timings.tsno longer readsprocess.env, and everytimings()read happens inside a function, so none of them sees the defaults before boot sets the values. - A start grace shorter than the ready window now throws. sidecar-cap overrides both.
- The harness is back to main's 15 s reconcile interval and the default liveness interval.
Publishedtakes its host keys fromREPO_SOURCES.- The unrouted title and DEV.md are fixed.
- The PR body names CL-11664 and CL-11665 and describes the one-time roll caused by the asset-hash change.
bun run lint and bun run check pass. The env, triage-contracts, triage-manager and workflow-release tests pass (358). CI is green.
One nit: docs/DEV.md says the chain starts its hub with "every Triage wait short", but the reconcile interval (15 s), liveness and stalled now keep their non-short values.
On shard 5: the test step logs only print one line per file, so the extra time can't be traced to a step inside pushed. pushed ended 65.8 s into the step on main and 89.8 s on c73adb7. About 4 s of that difference is in setup and about 19.5 s is in the single test body. Nothing in the logs ties it to the 1 s manager poll, the 100 ms poll, the single DB handle or the release.json timings read, so it is unexplained.
…hem in the release Every wait the hub, listener and manager share is one named timing in triage-contracts with its production value as default and a TRIAGE_*_MS override. The hub reads them once as it starts and writes the listener's and manager's share into their release.json, since a workflow's process gets none of the hub's environment; a tree without them runs on the defaults. The hub's deploy hold stays derived from the same ready window the listener waits.
The chain starts its hub with every Triage wait short and polls every 100 ms. No scenario sleeps for a fixed time or asserts a duration: woken waits for its manager to poll again, unset reads the hub's answer to the delivery, unrouted keeps the reconcile pass out of reach instead of timing the retry, and local-sidecars asserts each cause in its own test. A lint rule under tests/chain fails on a literal real sleep of a second or more, and AGENTS.md says a failed chain shard is read, never rerun.
TheGreatAxios
left a comment
There was a problem hiding this comment.
DEV.md now says the chain shortens the manager and listener waits, not every wait.
c73adb7 to
3b92b69
Compare
TheGreatAxios
left a comment
There was a problem hiding this comment.
No findings.
There was a problem hiding this comment.
Makes chain test scenarios assert state instead of waiting on production-sized timings, by moving every shared wait into a named, env-overridable timing set in triage-contracts with short values used by the chain harness. The main risks are a new response-parsing assumption in the test helper and a few assertions that became weaker or no longer catch late asynchronous behaviour.
| body, | ||
| }); | ||
| if (res.status !== 202) throw new Error(`The hub refused a ${event} delivery: ${res.status} ${await res.text()}`); | ||
| return ((await res.json()) as { status: string }).status; |
There was a problem hiding this comment.
P2 · deliver now parses every 202 body as JSON
deliver used to ignore the response body but now calls res.json() on every accepted delivery, including push and check_run deliveries whose result no caller uses.
If the hub answers any of those with an empty or non-JSON body, the call throws and the scenario fails even though the hub accepted the delivery. For example, the push in unset.test.ts would fail this way.
Suggested fix: only parse the body when the caller needs status, or guard the parse so a non-JSON 202 is treated as accepted:
const text = await res.text();
return text ? (JSON.parse(text) as { status: string }).status : "";| expect(failed.every((entry) => msOf(entry) < msOf(live) && entry["level"] === "info")).toBe(true); | ||
| expect(live["deployment"]).not.toBe(listener.id); | ||
| expect(msOf(sent) - msOf(live)).toBeLessThanOrEqual(MAILED_MS); | ||
| expect(msOf(sent)).toBeGreaterThanOrEqual(msOf(live)); |
There was a problem hiding this comment.
P2 · Retry timing assertion reduced to a lower bound, so a slow retry now passes
The test used to require the mail within MAILED_MS of the replacement starting. It now only checks that the mail came after the listener started:
expect(msOf(sent)).toBeGreaterThanOrEqual(msOf(live));
A reconcile retry that takes minutes, or fires only on a later pass, still passes, even though the test name promises the mail arrives once the replacement runs. The reconcile interval is 60 min, so the short retry is the only path left to mail the head, and that path is no longer checked.
Suggested fix: keep an upper bound tied to the configured retry, for example expect(msOf(sent) - msOf(live)).toBeLessThan(RETRY_MS * 3), or assert the retry fired through a hub-side signal.
| if (timings.managerStartGraceMs < timings.managerReadyMs) { | ||
| throw new Error(`${TIMING_VARIABLES.managerStartGraceMs} must be at least ${TIMING_VARIABLES.managerReadyMs}, ${timings.managerReadyMs} ms`); | ||
| } |
There was a problem hiding this comment.
P3 · Retry start not checked against the retry ceiling
timingsFrom cross-checks only the start grace against the ready window. reconcileRetryMs is now configurable, but nothing checks it against the fixed 120 s TRIAGE_RETRY_MAX_MS ceiling.
With TRIAGE_RECONCILE_RETRY_MS set above 120000, the documented 'doubling up to two minutes' behaviour breaks. Depending on createReconcileLoop, the first retry either exceeds the ceiling or is silently clamped to it.
Suggested fix: throw in timingsFrom when reconcileRetryMs exceeds the retry max, alongside the existing start-grace check.
| const withoutFile = { answered, claim: await claimOf(UNSET, 1), deployed: (await managers()).slice(before), writes: [...github.writesTo(UNSET, 1)] }; | ||
| github.setPolicy(UNSET, policy([MAX_FILES])); |
There was a problem hiding this comment.
P3 · No-policy check now reads state immediately after the delivery, dropping the wait that caught late deployments
The old 5 s sleep gave an asynchronous manager deployment for a repository without a policy file time to appear before deployed was read. The scenario now calls managers() right after pushed returns:
deployed: (await managers()).slice(before)
A deployment that starts a few seconds later, for example through a reconcile pass, is missed. The answered value only shows the synchronous answer, not that nothing started afterwards.
Suggested fix: poll managers() for a bounded window that is long enough for a reconcile pass to run, and assert it stays empty, instead of reading once.
…indow The listener mails a just-deployed manager at once. Interchange's hub-sessions sidecar handler parks mail to a run whose deploy is not recorded, redrives it when the deploy records the run's key, and drops it after HUB_MAIL_HOLD_TTL_MS. The listener's ready window, wake poll and its unwoken, retry and unwokenAgain steps are gone, as are the listener and manager waits #713 published in release.json. HUB_MAIL_HOLD_TTL_MS keeps its fifteen-minute default and is the one source for the hub's start grace, the time a manager may sit on its sidecar unstarted, the hold on a new deploy ask and the time a queued head may wait to start, so a failed manager start is asked again once the hold lapses.
…indow The listener mails a just-deployed manager at once. Interchange's hub-sessions sidecar handler parks mail to a run whose deploy is not recorded, redrives it when the deploy records the run's key, and drops it after HUB_MAIL_HOLD_TTL_MS. The listener's ready window, wake poll and its unwoken, retry and unwokenAgain steps are gone, as are the listener and manager waits #713 published in release.json. HUB_MAIL_HOLD_TTL_MS keeps its fifteen-minute default and is the one source for the hub's start grace, the time a manager may sit on its sidecar unstarted, the hold on a new deploy ask and the time a queued head may wait to start, so a failed manager start is asked again once the hold lapses.
…indow The listener mails a just-deployed manager at once. Interchange's hub-sessions sidecar handler parks mail to a run whose deploy is not recorded, redrives it when the deploy records the run's key, and drops it after HUB_MAIL_HOLD_TTL_MS. The listener's ready window, wake poll and its unwoken, retry and unwokenAgain steps are gone, as are the listener and manager waits #713 published in release.json. HUB_MAIL_HOLD_TTL_MS keeps its fifteen-minute default and is the one source for the hub's start grace, the time a manager may sit on its sidecar unstarted and the hold on a new deploy ask; a queued head waits the hold plus one reconcile interval before it is queued again, and a manager start that can no longer run is asked again on the next event.
…indow The listener mails a just-deployed manager at once. Interchange's hub-sessions sidecar handler parks mail to a run whose deploy is not recorded, redrives it when the deploy records the run's key, and drops it after HUB_MAIL_HOLD_TTL_MS. The listener's ready window, wake poll and its unwoken, retry and unwokenAgain steps are gone, as are the listener and manager waits #713 published in release.json. HUB_MAIL_HOLD_TTL_MS keeps its fifteen-minute default and is the one source for the hub's start grace, the time a manager may sit on its sidecar unstarted and the hold on a new deploy ask; a queued head waits the hold plus one reconcile interval before it is queued again, and a manager start that can no longer run is asked again on the next event.
…indow (#723) * refactor(listener): let stock's mail hold replace the manager ready window The listener mails a just-deployed manager at once. Interchange's hub-sessions sidecar handler parks mail to a run whose deploy is not recorded, redrives it when the deploy records the run's key, and drops it after HUB_MAIL_HOLD_TTL_MS. The listener's ready window, wake poll and its unwoken, retry and unwokenAgain steps are gone, as are the listener and manager waits #713 published in release.json. HUB_MAIL_HOLD_TTL_MS keeps its fifteen-minute default and is the one source for the hub's start grace, the time a manager may sit on its sidecar unstarted and the hold on a new deploy ask; a queued head waits the hold plus one reconcile interval before it is queued again, and a manager start that can no longer run is asked again on the next event. * fix(hub): keep listener wakes tolerant and the portal's start grace at two minutes * fix(hub): count a just-deployed run live for the listener's start grace
Chain scenarios no longer wait on production-sized windows. Every wait the hub, listener and manager share is now one named timing. Each has its production value as default and a
TRIAGE_*_MSoverride. The chain starts its hub with short values, and each scenario waits on the state it names.What changed
triage-contractsdefines the waits, with defaults unchanged, and onetimingsFrom(env)reader. It throws when the manager start grace is shorter than the ready window.loadHubEnvlike every other variable: a blank value keeps its default, and a bad value shows up in its combined error. Boot sets them once.release.json, because a workflow's process gets none of the hub's environment. A tree without them runs on the defaults..env.exampleand SELF_HOST.TIMINGSintests/chain/stack.ts: ready and start grace 60 s, manager poll 1 s, wake poll 100 ms, reconcile retry 1 s, coalesce 500 ms. The reconcile interval stays at main's 15 s. Polling is every 100 ms, with one database handle per stack.needs-setupanswer to the delivery.tests/chain/.oxlintrc.jsonfailsbun run linton a literal sleep or timer of 1 s or more. The root config stays data-only, so the code-review lint step still runs on this repo.On deploy
On the first deploy after this, every workspace's listener and manager asset hash changes, because their
release.jsonnow always carries the waits. Each workspace rolls its listener once.Left out
tests/chain/: CL-11664.Verification
bun run lintandbun run checkpass. The unit tests for triage-manager, triage-contracts, the hub's env, manager state and workflow-release pass.Scenario times
All columns are CI test time, without the stack's setup, one run each.
What changed between the two PR runs:
Closes CL-11645