Skip to content

Give other requests a turn: yield between batch entries, every 10 ms, and during the startup scan - #338

Open
jmandel wants to merge 3 commits into
HealthIntersections:mainfrom
jmandel:fix/event-loop-yields
Open

jmandel wants to merge 3 commits into
HealthIntersections:mainfrom
jmandel:fix/event-loop-yields

Conversation

@jmandel

@jmandel jmandel commented Nov 3, 2026 •

Copy link
Copy Markdown
Contributor

Three changes to when long work gives the event loop back, one commit each. They change scheduling, not answers: every result is the same, and each test checks that. They are apart from the correctness fixes (#337) because they are tuning. The 10 ms one, in particular, changes every long operation on the strength of one measurement, so you may want to take the other two and leave it.

  1. $batch-validate-code: give other requests a turn between entries
  2. Long operations yield every 10 ms of compute instead of every 25
  3. ConceptUsageTracker: yield during the startup scan

1. $batch-validate-code: give other requests a turn between entries

Register row P3.

What was wrong

Validating one entry of a batch never yields the event loop, and IG builds send batches of up to 1,000 codes. A 1,000-code batch held the event loop for about 1 s, and every request that arrived meanwhile waited for it. Batches are 3% of IG Publisher calls, but 46% of the work.

Measured locally on main: a real 1,000-code SNOMED CT batch from an IG build ran while a single-code $validate-code was sent every 10 ms. On its own that lookup takes 4–6 ms. During the batch:

  • before: the lookups typically waited 0.6–0.9 s, the worst 1.35 s;
  • after: they typically took about 50 ms, the worst 73–238 ms, and none took over 1 s.

The batch was no slower (5 runs each). We didn't run this against tx-dev, since it means sending a heavy batch alongside a stream of lookups.

Code path

tx/workers/batch-validate.js, BatchValidateWorker.processBatch (line 87): the loop over validation entries (line 107) has no yield point.

Change

await this.opContext.checkAndYield('batch-validate') before each entry. checkAndYield (tx/operation-context.js:1001) yields only after YIELD_INTERVAL ms (25) of compute, so small batches are unaffected. The results are unchanged.

The next section proposes yielding every 10 ms instead of 25. This change doesn't depend on it.

Test

tests/tx/batch-validate-yield.test.js: a five-entry batch calls checkAndYield('batch-validate') once per entry, and gives the same five results. The test fails on main (no calls) and passes with the change.

2. Long operations yield every 10 ms of compute instead of every 25

Register row P3 (follow-up).

What was wrong

A request that arrives while a long operation runs waits for the rest of the operation's current compute slice, then its own turn. With 25 ms slices, that is about two slices.

In the same experiment as the batch yield (a 1,000-code SNOMED CT batch with a lookup sent every 10 ms, on our development branch with the same yield code), changing 25 to 10 gave:

  • a lookup's wait: typically 22 ms instead of 51 (worst 42 instead of 86);
  • the batch: 842 ms instead of 879, so no measurable cost.

That is the only measurement; it was not repeated under full load.

Code path

tx/operation-context.js: YIELD_INTERVAL (line 827) is 25. OperationContext.checkAndYield (line 1001) yields once that many ms of compute have passed since the last yield. Every long loop that calls checkAndYield ($expand and the others) uses it.

Change

YIELD_INTERVAL is 10. This is a tuning choice for every operation that calls checkAndYield, so it is its own commit. It's most useful together with the batch-validate yield, which gives batches a place to yield at all, but either can be taken alone.

Test

tests/tx/operation-context-yield.test.js, "the slice length": with performance.now mocked, checkAndYield doesn't yield 9 ms after the last yield and does at 10 ms. It fails on main (25) and passes with the change. The rest of that suite (slicing, the deadline charged against compute, abandoning when the client has gone) passes unchanged.

3. ConceptUsageTracker: yield during the startup scan

Register row P4.

What was wrong

Just after startup, the tracker reads every value set: 3,989 with tx.fhir.org's sources. That is about 1 s of work without a break. Requests arriving then waited for all of it; the stall log at startup shows it next to "scan complete: 3989 valuesets".

This happens once per start, so there's no curl for it on a running server.

Code path

tx/usage-tracker.js, ConceptUsageTracker.scanValueSets (line 8): the loop over each provider's value sets (line 12) never yields.

Change

Give the event loop a turn (setImmediate) every 10 ms of the scan. The counts are the same. This uses its own constant, since the tracker has no OperationContext.

Test

tests/tx/usage-tracker-yield.test.js: a scan of 100 value sets that take 1 ms each to fetch lets a setImmediate loop run more than 3 times, and gives the same counts. On main the loop doesn't run during the scan; with the change it does.

Results

🤖 Generated with Claude Code

jmandel and others added 3 commits November 3, 2026 11:36
Validating an entry never yields, so a 1,000-entry batch from an IG build held the event loop
for about 1 s and every request arriving meanwhile waited for it. checkAndYield before each
entry; it only yields after YIELD_INTERVAL ms of compute, so small batches are unaffected.

Measured on main with a real 1,000-code SNOMED CT batch running and a single-code
$validate-code (4-6 ms on its own) sent every 10 ms: those lookups typically waited 0.6-0.9 s
(worst 1.35 s) before, about 50 ms (worst 73-238 ms) after; the batch was no slower.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
While a long operation runs, other requests wait about two slices: 22 ms typical instead of 51
(worst 42 vs 86) during a 1,000-code batch, with no measurable cost to the batch (842 vs 879 ms).
Measured with a single lookup sent every 10 ms during the batch.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The scan that runs just after startup reads every value set (about 4,000 with tx.fhir.org's
sources) and held the event loop for about a second, so requests arriving then waited for all
of it. It now gives the event loop a turn every 10 ms of work. Same counts.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@grahamegrieve

Copy link
Copy Markdown
Contributor

Thanks - looks good. Two things:

  1. This conflicts with VSAC: read value sets from the database when asked for, instead of holding them all in memory #333 in tx/usage-tracker.js: VSAC: read value sets from the database when asked for, instead of holding them all in memory #333 replaces the loop with
    vsp.scanAllValueSets(callback). I'll merge VSAC: read value sets from the database when asked for, instead of holding them all in memory #333 first; could you then rebase and move the
    yield into the callback?

  2. The checkAndYield before each entry also runs deadCheck, outside the per-entry try, so
    any trip now fails the whole batch with 422. For the memory abort that's right: answering
    the rest of the batch only allocates more. For the time limit I'd rather keep main's
    behaviour, where the entries answered before the limit keep their answers and the rest get
    too-costly. Could you mark the memory-abort Issue (e.g. error.memoryAbort = true), rethrow
    only that from the per-entry catch, and add a test for each case?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants