Skip to content

Commit c59a0fa

Browse files
authored
Merge pull request #6264 from cardstack/cs-13037-the-link-shape-ladders-load-reading-counts-computations-not
Decide the link-shape ladder on search requests in flight, not computations
2 parents 9e14aff + 495b9a9 commit c59a0fa

17 files changed

Lines changed: 728 additions & 383 deletions

File tree

‎.claude/skills/indexing-diagnostics/SKILL.md‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -940,7 +940,7 @@ It is **not** persisted in `boxel_index.diagnostics` (that's the client side). S
940940
```
941941
corr=<id> job=<jobId> handler=Nms parse=… resolveRealms=… sql=… stringify=… coalescedWait=… | results=… (realm:search-timing)
942942
--> QUERY <accept> <url>: 200 [job: <jobId>] corr=<id> dur=Nms (realm:requests)
943-
eventLoopLagMs(mean/p99/max)=…/…/… inFlightSearch=… heapMB=… (realm:health)
943+
eventLoopLagMs(mean/p99/max)=…/…/… inFlightSearch=… searchRequests=… searchLoad=… heapMB=… (realm:health)
944944
```
945945

946946
The `|`-section is the **sequential wall-clock timeline** (these sum to ≈ `handler`).

‎.claude/skills/realm-load-harness/SKILL.md‎

Lines changed: 16 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -464,11 +464,14 @@ per-render total:
464464

465465
## Getting a run to a threshold, and telling whether it did
466466

467-
Two realm-server mechanisms engage at a level of concurrency: the admission gate
468-
bounds in-flight searches at a cap, and the link-shape policy degrades a live
469-
read's link closure one rung earlier, at a time-weighted mean of the same count
467+
Two realm-server mechanisms engage at a level of concurrency, on two different
468+
counts: the admission gate bounds concurrent search _computations_ at a cap,
469+
and the link-shape policy degrades a live read's link closure once a
470+
time-weighted mean of concurrent search _requests_ — joiners included, which
471+
the gate stops counting at the cache decision — crosses one of its rungs
470472
(120-second half-life by default, `LINK_SHAPE_LOAD_HALF_LIFE_MS` per
471-
deployment). Both are **per replica**, so a fleet of N tasks needs N times the
473+
deployment). The rungs are placed against sustained request load, not below
474+
the point where the gate starts shedding. Both are **per replica**, so a fleet of N tasks needs N times the
472475
load one process would.
473476

474477
The gate does not shed at the cap: an arrival above it queues and is answered
@@ -482,16 +485,15 @@ could not have engaged. Two different questions, two different answers:
482485

483486
- **Is the threshold where real traffic can reach it?** That needs load, and
484487
the credential pool is the ceiling: one session per CSV row, so a 20-row file
485-
caps a run at 19 readers. At `--derive-page-size 0` that held a peak
486-
120-second mean of **6.3** searches in flight. Read it against the rungs and
487-
the cap in `packages/runtime-common/search-bounds.ts`: that run cost about
488-
three readers per unit of mean, so the lower rung at 4 wants roughly 13
489-
readers and the upper one at 12 roughly 36, **per replica**. So a pool of
490-
this size already clears the lower rung, while the upper rung and the
491-
admission cap still need one several times larger. Those are a floor, not an
492-
estimate — the scaling is linear only while service time holds, and service
493-
time is what rises first as a realm saturates. Growing the pool is the only
494-
fix, and it is what puts the admission queue under enough pressure to shed.
488+
caps a run at 19 readers. At `--derive-page-size 0` against a two-replica
489+
deployment, that held the policy's reading — the 120-second mean of search
490+
requests in flight, per replica, joiners included — at a p50 of about 14-17
491+
and a peak of about 21-22. Read it against the rungs in
492+
`packages/runtime-common/search-bounds.ts`: a pool of this size clears the
493+
lower rung at 14 and does not reach the upper one at 28. The scaling is
494+
linear only while service time holds, and service time is what rises first
495+
as a realm saturates. Growing the pool is the only fix, and it is what puts
496+
the admission queue under enough pressure to shed.
495497

496498
The reading is also a count and not a cost: `inFlight` moves once per
497499
admitted search whatever that search is doing. An unbounded derived workload

‎.claude/skills/search-shape-diagnosis/SKILL.md‎

Lines changed: 12 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -176,7 +176,7 @@ packages/observability/scripts/tail-logs.sh --env staging --service realm-server
176176

177177
## The link-shape policy
178178

179-
How much of each result's link graph a live read carries is decided per realm from the load the process is under, one rung below admission control: a saturated process degrades a response before it refuses a request. Two channels record it — the per-request fields above, and a low-volume transition channel, `boxel:link-shape-policy`, on the same `| json` convention.
179+
How much of each result's link graph a live read carries is decided per realm from the load the process is under: under sustained request load, a process degrades a response rather than serving its full link closure. This is independent of admission control, which refuses requests on bursts against its cap and can do so at readings below the lower rung. Two channels record it — the per-request fields above, and a low-volume transition channel, `boxel:link-shape-policy`, on the same `| json` convention.
180180

181181
A policy that reacts to load is only debuggable if it records the conditions it reacted to, because by the time anyone asks "why was this page slow" the concurrency that caused the decision is gone. These are the two questions an operator actually arrives with.
182182

@@ -233,18 +233,18 @@ A `dwellMs` of `null` is a realm's first move, not a zero-length dwell — it ha
233233
### The thresholds: what they mean and how to set them
234234

235235
Four values decide when a realm changes rung. All four are **thresholds on the
236-
load reading** — the time-weighted mean of in-flight searches, per replica —
236+
load reading** — the time-weighted mean of search requests in flight, joiners included, per replica —
237237
and none of them selects a link shape. Which shape a rung serves is fixed by
238238
the ladder; these only decide when a realm arrives at that rung. The
239239
`_THRESHOLD` suffix is there because a bare `…_ENGAGE` reads as a switch that
240240
turns a shape on, which is the one thing it does not do.
241241

242242
| Parameter | Ships as | Crossing it |
243243
| ---------------------------------------- | -------: | ------------------------------------------------------------------------- |
244-
| `LINK_SHAPE_MULTI_ROW_ENGAGE_THRESHOLD` | 4 | reads that may return more than one row start shedding their link closure |
245-
| `LINK_SHAPE_MULTI_ROW_RELEASE_THRESHOLD` | 2 | those reads carry it again |
246-
| `LINK_SHAPE_ALL_ENGAGE_THRESHOLD` | 12 | every live read sheds it, including a single-card read |
247-
| `LINK_SHAPE_ALL_RELEASE_THRESHOLD` | 6 | single-row reads carry it again |
244+
| `LINK_SHAPE_MULTI_ROW_ENGAGE_THRESHOLD` | 14 | reads that may return more than one row start shedding their link closure |
245+
| `LINK_SHAPE_MULTI_ROW_RELEASE_THRESHOLD` | 7 | those reads carry it again |
246+
| `LINK_SHAPE_ALL_ENGAGE_THRESHOLD` | 28 | every live read sheds it, including a single-card read |
247+
| `LINK_SHAPE_ALL_RELEASE_THRESHOLD` | 14 | single-row reads carry it again |
248248

249249
Three more shape the same mechanism without being rungs:
250250
`LINK_SHAPE_LOAD_HALF_LIFE_MS` (120000, how far back the mean reaches),
@@ -255,7 +255,7 @@ All seven are settable the same way.
255255
Four properties decide whether a change to any of these does what you expect:
256256

257257
1. **Per replica, no shared store.** Each process reads only its own
258-
admissions, so a fleet-wide in-flight of 12 spread over N tasks is ~12/N
258+
requests, so a fleet-wide in-flight of 28 spread over N tasks is ~28/N
259259
per replica. A threshold is only meaningful stated together with the fleet
260260
size it was chosen against, and adding tasks raises the fleet-wide load
261261
needed to engage roughly linearly. Read the current count rather than
@@ -271,9 +271,10 @@ Four properties decide whether a change to any of these does what you expect:
271271
3. **Every rung change costs a realm its cached validators.** The link mode is
272272
folded into both response validators and keys the card+json response cache,
273273
so a lower engage buys earlier protection and pays in cache fragmentation
274-
landing exactly when the server is busiest. That trade is the reason the
275-
upper rung sits at 12: lowering it to 8 raised a quiet control window's
276-
degraded time from 0.3% to 3.8%.
274+
landing exactly when the server is busiest. The upper rung, which degrades
275+
even single-card reads, is placed above every load it has been observed on,
276+
because nothing has measured it helping; `search-bounds.ts` records the
277+
evidence for each rung.
277278

278279
The fragmentation _rate_, though, does not track the engage as directly as
279280
that trade suggests, so "lower engage, more flapping" is not a safe thing to
@@ -349,7 +350,7 @@ Three of these cost real time on the investigation that produced the policy, and
349350
- **`busyMs(parallel-sum)` is not CPU.** It sums concurrently-awaited work, so it double-counts waiting — it has read 46× wall clock on a single-threaded loop. It cannot be used to argue the process was or was not saturated.
350351
- **The `realm:search-timing` stage lines carry no job marker.** A `loadLinks` share computed from them mixes worker traffic into live: in one 55-minute window 533 of 1,355 searches were `prerender`/job traffic. Separate them with this channel's `jobId` (via `correlationId`), not with the stage lines alone.
351352

352-
One more, specific to the policy: the load it reads is the **sustained** in-flight count — a time-weighted mean with a multi-minute half-life — not the instantaneous `inFlightSearch` the health line prints. They differ by design and by a lot: on a production window whose raw samples repeatedly touched the admission cap of 30, the sustained reading peaked at 17. Comparing a `linkShapeLoad` against a health line's `inFlightSearch=` at the same timestamp will look like a contradiction and is not one.
353+
One more, specific to the policy: the load it reads is the **sustained count of search requests in flight** — every admitted request from admission until its response ends, joiners included, as a time-weighted mean with a multi-minute half-life. It is not the health line's `inFlightSearch`, which differs from it twice over: `inFlightSearch` is an instantaneous sample, and it counts admission slots — computations — which a request the live-search cache answers from another's computation hands back early, so it runs below the request count by the cache's miss rate. The health line carries the policy's own quantity as `searchLoad=` (and its instantaneous form as `searchRequests=`); compare `linkShapeLoad` against that, never against `inFlightSearch=`.
353354

354355
## Authoring a replay
355356

‎docs/realm-server-health-signals.md‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -71,9 +71,16 @@ those cases, but it is a reason not to over-trust a 200 here on its own.
7171
lag crosses a threshold or a search is in flight:
7272

7373
```
74-
eventLoopLagMs(mean/p99/max)=… inFlightSearch=… heapMB=…
74+
eventLoopLagMs(mean/p99/max)=… inFlightSearch=… searchRequests=… searchLoad=… heapMB=…
7575
```
7676

77+
`inFlightSearch` counts admission slots — concurrent search _computations_,
78+
since a request the live-search cache answers from another's computation hands
79+
its slot back early. `searchRequests` counts every admitted search request until
80+
its response ends, and `searchLoad` is that count's time-weighted mean, which is
81+
the reading the link-shape policy's thresholds are compared against. The first
82+
two differ by the live-search cache's miss rate.
83+
7784
Silent on an idle, healthy server — so its presence in the logs is itself the
7885
signal. Lag climbing in step with `inFlightSearch` is the fingerprint of the loop
7986
being starved by concurrent search serialization.

‎packages/observability/provisioning/alerting/realm-server-availability-group.json‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -482,7 +482,7 @@
482482
"title": "Realm Server Search Saturation",
483483
"condition": "B",
484484
"annotations": {
485-
"summary": "A realm-server process reached 15+ concurrent _search / _federated-search requests at least once in the last 5 minutes (baseline is single digits). Sourced from the periodic health line (inFlightSearch=N, which counts both routes — including the in-render _search round-trips prerender issues). Concurrent search load drives heap growth toward OOM — this is the early-warning signal; find which client/realm is issuing the searches."
485+
"summary": "A realm-server process reached 15+ concurrent _search / _federated-search computations at least once in the last 5 minutes (baseline is single digits). Sourced from the periodic health line (inFlightSearch=N: admission slots, which counts both routes — including the in-render _search round-trips prerender issues — but not requests the live-search cache answers from another computation; searchRequests=N counts those too). Concurrent search load drives heap growth toward OOM — this is the early-warning signal; find which client/realm is issuing the searches."
486486
},
487487
"data": [
488488
{

‎packages/realm-server/handlers/handle-search.ts‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -560,7 +560,9 @@ async function respondWithJobScopedSearchCache(
560560
// A joiner or a hit holds no result document of its own, so it stops
561561
// counting toward the search admission ceiling here rather than when
562562
// its response ends; the ceiling is then a bound on concurrent
563-
// computations, which is what holds the heap.
563+
// computations, which is what holds the heap. The request itself stays
564+
// counted toward the link-shape policy's reading until its response
565+
// ends, because it goes on waiting for the computation it joined.
564566
onOutcome: (decided) => {
565567
recordCacheOutcome(decided);
566568
if (decided !== 'miss') {

‎packages/realm-server/health-sampler.ts‎

Lines changed: 17 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,10 @@
11
import { monitorEventLoopDelay, type IntervalHistogram } from 'node:perf_hooks';
22
import { logger } from '@cardstack/runtime-common';
3-
import { getSearchInFlight } from './search-inflight.ts';
3+
import {
4+
getSearchInFlight,
5+
getSearchRequestLoad,
6+
getSearchRequestsInFlight,
7+
} from './search-inflight.ts';
48
import {
59
heapTelemetry,
610
formatHeapTelemetry,
@@ -49,6 +53,16 @@ export function startHealthSampler(
4953
let p99LagMs = toMs(histogram.percentile(99));
5054
histogram.reset();
5155
let inFlightSearch = getSearchInFlight();
56+
// The link-shape policy's own inputs, beside the lag they are placed
57+
// against. `inFlightSearch` counts admission slots, which a request the
58+
// live-search cache answers from another's computation gives back early;
59+
// `searchRequests` counts every admitted request until its response ends,
60+
// and `searchLoad` is that count's sustained mean, the number the ladder's
61+
// thresholds are compared against. A threshold derived from one of these
62+
// and applied to another is off by the cache's miss rate, or by whatever
63+
// the smoothing takes off a burst.
64+
let searchRequests = getSearchRequestsInFlight();
65+
let searchLoad = getSearchRequestLoad();
5266
// Reuse the prerender heap-telemetry helpers so the realm-server health
5367
// line carries the same `heapUsedMB=… heapLimitMB=…` fields (one spelling
5468
// of the quantity, and the effective V8 limit read from the running
@@ -57,7 +71,8 @@ export function startHealthSampler(
5771
let heap = heapTelemetry();
5872
log.info(
5973
`eventLoopLagMs(mean/p99/max)=${meanLagMs.toFixed(0)}/${p99LagMs.toFixed(0)}/${maxLagMs.toFixed(0)} ` +
60-
`inFlightSearch=${inFlightSearch} ${formatHeapTelemetry(heap)}`,
74+
`inFlightSearch=${inFlightSearch} searchRequests=${searchRequests} ` +
75+
`searchLoad=${searchLoad.toFixed(2)} ${formatHeapTelemetry(heap)}`,
6176
);
6277
}, intervalMs);
6378
// Don't keep the process alive solely for sampling.

‎packages/realm-server/middleware/index.ts‎

Lines changed: 29 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ import {
2828
import {
2929
admitSearch,
3030
admitSearchUnconditionally,
31+
beginSearchRequest,
3132
getSearchAdmissionLimit,
3233
getSearchInFlight,
3334
getSearchShedCount,
@@ -249,8 +250,11 @@ const SEARCH_ADMISSION_RELEASE = 'searchAdmissionRelease';
249250
// ceiling; only the request doing the computing keeps its slot until its
250251
// response ends. That holds for an indexing-lane admission too: an in-render
251252
// search served from another request's computation holds no document either,
252-
// and the count is of computations, whichever lane admitted them. Idempotent,
253-
// and a no-op for requests the gate never saw.
253+
// and the count is of computations, whichever lane admitted them. Only the slot
254+
// is handed back: the request goes on counting toward the link-shape policy's
255+
// reading until its response ends, since it is still waiting on the
256+
// computation it joined. Idempotent, and a no-op for requests the gate never
257+
// saw.
254258
export function releaseSearchAdmission(ctxt: Koa.Context): void {
255259
let release = ctxt.state[SEARCH_ADMISSION_RELEASE];
256260
if (typeof release === 'function') {
@@ -263,7 +267,9 @@ export function releaseSearchAdmission(ctxt: Koa.Context): void {
263267
// (parse → SQL → serialize → send), which is the window in which it holds heap
264268
// and in which a saturated event loop would leave it unserviced; one that the
265269
// live-search cache serves from another's computation hands the slot back
266-
// early via `releaseSearchAdmission`. Mounted after CORS so that a shed
270+
// early via `releaseSearchAdmission`. Every admitted request, whichever it
271+
// is, is also counted as a request in flight until its response ends, which is
272+
// the reading the link-shape policy decides on. Mounted after CORS so that a shed
267273
// response carries the headers a cross-origin client needs to read its status
268274
// and Retry-After; before the body is parsed so that a shed costs nothing.
269275
export async function searchAdmission(ctxt: Koa.Context, next: Koa.Next) {
@@ -283,17 +289,27 @@ export async function searchAdmission(ctxt: Koa.Context, next: Koa.Next) {
283289
let arrivedAt = Date.now();
284290
let closed = false;
285291
let release: (() => void) | undefined;
292+
let endRequest: (() => void) | undefined;
286293
let releaseSlot = () => {
287294
release?.();
288295
release = undefined;
289296
};
297+
// The slot and the request end separately: a request the live-search cache
298+
// serves from another's computation hands its slot back early, but it is
299+
// still a request in flight — waiting on that computation — until its
300+
// response ends, and that is the count the link-shape policy reads.
301+
let end = () => {
302+
releaseSlot();
303+
endRequest?.();
304+
endRequest = undefined;
305+
};
290306
ctxt.state[SEARCH_ADMISSION_RELEASE] = releaseSlot;
291307
// `finish` fires on a fully-sent response; `close` covers a connection
292-
// torn down before that, so a slot can't leak on an abort.
293-
ctxt.res.on('finish', releaseSlot);
308+
// torn down before that, so neither count can leak on an abort.
309+
ctxt.res.on('finish', end);
294310
ctxt.res.on('close', () => {
295311
closed = true;
296-
releaseSlot();
312+
end();
297313
});
298314

299315
if (isIndexing) {
@@ -313,6 +329,13 @@ export async function searchAdmission(ctxt: Koa.Context, next: Koa.Next) {
313329
}
314330
release = admitted;
315331
}
332+
// Only a request whose connection is still open starts counting. The
333+
// `close` listener is what ends the count, so a request that began after
334+
// its close had already fired would never be ended — and a leaked request,
335+
// unlike a leaked slot, holds the replica's load reading up until restart.
336+
if (!closed) {
337+
endRequest = beginSearchRequest();
338+
}
316339
return next();
317340
}
318341

0 commit comments

Comments
 (0)