perf(aglake): id lookups fan out, because every search term costs the same - #200
perf(aglake): id lookups fan out, because every search term costs the same#200vaderyang wants to merge 2 commits into
Conversation
… same aglake charges a fixed cost per search-position term — linear in the term count, independent of how many events match — so the no-JOIN read pattern paid for every id serially. Batching the ids into one `id IN (…)` was the slowest available shape, not the cheapest. Measured on a production instance: opening a 376-call turn took 15.7 s, of which 14.1 s was the single bodies lookup, and the services topology graph took 6.0-6.5 s on every call. Not payload — the same terms with `| stats count` and no rows returned still took 12.8 s, where a term-free scan of the same window took 302 ms. So ID_CHUNK drops 512 -> 32 and the chunks run concurrently rather than in a `for` loop. 14.1 s -> 4.7 s for the bodies lookup at the default limit, 7.1 s -> 1.2 s for topology. Chunking further is slower: at 4 ids per search the per-search overhead dominates and the bodies lookup regresses to 11.2 s, so the constant is a measured optimum rather than a minimum. max_concurrent_searches stops being accepted-and-ignored and becomes that bound, enforced on the one method every read path goes through so it limits the total instead of being a per-query number that k concurrent console requests multiply by k. 0 clamps to 1 and is reported by `config validate`, because read as "unlimited" it would block the first read forever. The session-list fan-out keeps the large chunk on purpose: it matches many rows per id rather than one, and its `| head max_sessions_scan` budget is written per search, so splitting the id set would have multiplied that budget by the number of chunks. Tests: a mock that measures its own in-flight high-water mark (a no-op semaphore passes every other assertion and fails only that one), and a live turn of 2*ID_CHUNK+1 spans — every existing test used three, one chunk, so the split was never taken. Verified both fail without the change: dropping a chunk loses span-0032, the first id of the second chunk. Claude-Session: https://claude.ai/code/session_01GxGWpo3L4BRMkwtoa9X54W
There was a problem hiding this comment.
Suggestions
-
server/h-storage-aglake/src/client.rs:810 — Tokio's
Semaphore::acquireis fair (FIFO), and the three fan-out sites now hand every chunk tosearch()in onetry_join_all. WithID_CHUNK = 32a 10,000-turn topology window is 313 queued chunks, and a concurrent console request (a turn open, a span detail) queues its chunks behind all of them. Before this PR each read path held its own loop, so a small query could interleave. Consideracquire_many/a per-caller bound, or at minimum note the convoy inAglakeConfig::max_concurrent_searches' doc — the current wording ("k concurrent console requests share the budget instead of multiplying it") is true about total load but reads as if fairness were free. -
server/h-storage-aglake/src/calls.rs:303 — With
ID_CHUNKat 32 rather than 512, theNone-window path (query_spans_by_ids, ids from the in-memory registry) now runs up to 2 chunks' worth offetch_raw_by_idretries per 64 ids, each of which can fall through to an unbounded query (read.rs:69) when the id-derived window misses — the exact replay case the doc comment there calls guaranteed. That's more simultaneous full-retention scans than before, not fewer, on the one path that has no window to prune with. Worth confirming against a replayed corpus thatquery_spans_by_idsdidn't regress; the newit.rstest covers the ordering, not the miss cost. -
server/h-storage-aglake/src/services.rs:462 —
endpoints_for_span_idsfans out overMAX_TOPOLOGY_TURNS(10,000) first-span ids, so the chunk count is bounded by turns, not by anything the semaphore says. That is now 313 searches where it used to be 20, all admitted at once and serialized by the permit. The commit measures 1.2 s on one production window; a busier window scales the queue linearly. A| headbudget or a lower cap for this specific fan-out would keep the tail bounded. -
docs/design/10-aglake.md:184 — "
id IN ("a","b",…)in chunks of 512" is now wrong in two ways: the size is 32, and the reason for chunking changed from query-string bound to concurrency. Thespl.rsdoc comment carries the full rationale but the design doc — the stated AI-dev reference — still points at the old constant. -
server/h-common/src/config.rs:1745 — The
0check is emitted insideif self.storage.backend == AGLAKE_BACKEND, which matches the siblingAglakePasswordWithoutUsernameand the doc comment says so explicitly. ButSearchClient::newclampsmax(1)unconditionally, so a config that is not on the aglake backend today and is switched to it later gets no warning on the switch. Minor: the gating is consistent with the surrounding issues, so this is a note rather than a defect. -
server/h-storage-aglake/src/client.rs:2344 —
a_failed_search_returns_its_permitbuilds its ownAglakeConfigliteral rather than reusing theCountingAglake::confighelper, so it duplicates four fields. FoldingFailingAglakeinto the same helper shape would keep the two mocks from drifting.
Questions
-
The commit message says "drop
--search-threads" nowhere butdefault.toml:189tells operators to "raise--search-threadsalongside it on a search-heavy box." Ismax_concurrent_searches = 8deliberately pinned to aglaked's default scan pool so that raising it is opt-in, and if so, shouldconfig validatewarn when it exceeds a number Heron can't read back from the daemon? Right now the operator has no signal that they've oversubscribed. -
CHANGELOG.md:23andspl.rs:286both citeID_CHUNK 512 → 32, but the table atspl.rs:274–279measures 64 as faster (4.1 s) than 32 (4.7 s) on the bodies index, and says 16 measured better on the spans/traces indexes. Is 32 chosen as the value that is within noise of the optimum on all indexes rather than the bodies optimum specifically? The doc says so, but the CHANGELOG rounds it to "measured optimum" without that qualifier — a reader tuning for the bodies-heavy path would pick 64. -
client.rs:2344's failing mock answers500with a body of{"error":"boom"}. Doesdescribe_search_failure(client.rs:858) hit the_arm for a 500, and does the retry logic inWriteBuffer/read paths treat a 500 the same as the 401 path the permit test is exercising? The test asserts "the third response is a success" but not what the first two errors were.
Verified
- Leakage: scanned the diff for private IPs, credentials, key material, internal hostnames, and machine paths — the new tests bind
127.0.0.1:0, the new docs reference "a production instance" generically, and no config example carries real infra. Clean. - Schema mirror: no Rust struct fields added or renamed; the only
pubsurface change isAglakeZeroConcurrentSearches, aConfigIssuevariant, which is not mirrored inconsole/src/types/api.ts(that file carries no config-issue type). - ConfigIssue exhaustiveness:
severity()(config.rs:1359) andDisplay(config.rs:1502) both add arms; the two consumers (cmd/validate.rs,cmd/doctor.rs) match onseverity()/to_string(), not on the enum, so no non-exhaustivematchbreaks. - Version SSOT:
VERSION,server/Cargo.toml:11, andconsole/package.jsonall read 0.8.1;Cargo.lockbump to 0.8.1 matches. No version drift introduced. futureswiring:server/Cargo.toml:33adds it toworkspace.dependencies,h-pcap-extract/Cargo.toml:14converts its direct dep to.workspace = true,h-storage-aglake/Cargo.toml:16adds it. Both crates' existingfutures::usages (pcap-extractStreamExt/poll_fn) are compatible with the plain"0.3"default features.- Caller compatibility: grepped
read_spans_by_ids(3 callers:query_trace_spans,query_spans_by_ids, and the new test),fetch_bodies(1 caller),endpoints_for_span_ids(1 caller). Signatures are unchanged; only the internal loop shape moved. - Body-scan check: no
arg_max(body, …),MAX(body), orLENGTH(body)in the diff; the two DuckDB hits atmetrics.rs:848/1070are pre-existing and outside this change. ConfigIssue0-clamp test:config.rs:3007asserts the variant fires for0and stays silent for1and the default — matches the runtime clamp atclient.rs:793.
Agent output was missing required heading.
🤖 Reviewed by the review bot • workflow run
Upstream fixed the cost this change was measured against. The per-term cost on
dictionary-less (unsealed) buckets was quadratic per event — three linear
scans in the residual lookup structures, no short-circuit on a miss — and
`sglog-ystd` turns them into index lookups. That is worth ~4x on its own.
So the constant had to be re-derived against a daemon carrying the fix rather
than kept on numbers taken from one without it. 400 span ids against a hot
bucket, 8 permits, five interleaved reps on one host:
chunk searches 1.5.0.2674 sglog-ystd fixed
400 1 6423 ms 1596 ms
128 4 1670 ms 679 ms
96 5 1254 ms 555 ms
64 7 887 ms 455 ms
48 9 1047 ms 655 ms
32 13 1051 ms 658 ms
64 wins on both, and the optimum is sharp in both directions — fewer, bigger
searches leave the permits idle; more, smaller ones pay aglaked's per-search
overhead more times than the terms save. 32 was costing 1.19x the optimum on
the unfixed daemon and 1.45x on the fixed one.
I had this number in the first measurement and waved it off: 64 measured 4137 ms
against 32's 4664 on the real bodies hop, and I called 13% "within noise across
the three hops" and took the compromise. It was not noise.
What the fix does not do is make the fan-out redundant, which was the live
question for this branch: concurrency is still worth 3.5x after it, and the
shape is unchanged. Per-term cost now falls with term count (4.02 ms/term at
400 against 10.1 at 32), so the marginal term is cheap — but the total still
grows with N, and only the fan-out shortens the wall clock. 8 permits x 64 ids
also happens to resolve up to 512 ids in one wave, covering every turn seen.
Verified by building aglaked from source at the commit carrying the fix and
A/B-ing it against the version in production on two copies of the same real
index. Workspace 1236 passed; the live suite 141 passed against a current
daemon build.
Claude-Session: https://claude.ai/code/session_01GxGWpo3L4BRMkwtoa9X54W
|
Upstream fixed the cost this branch was measured against, so I re-derived the What upstream changedThe per-term cost on dictionary-less (unsealed) buckets was quadratic per event: Worth stating that no released build has it yet — the newest published nightly Re-derived: 400 span ids against a hot bucket, 8 permits, 5 interleaved reps
64 wins on both builds and the optimum is sharp in both directions: fewer, I had this number in the first measurement and waved it off — 64 measured The fan-out is not redundant after the fixStill 3.5× faster than one search, and the shape is unchanged. Per-term cost now VerificationBuilt aglaked from source at the fixing commit and A/B'd it against the version Workspace 1236 passed; the live suite 141 passed against a current daemon build. |
aglake charges a fixed cost per search-position term — linear in the number
of terms, independent of how many events match. That makes the no-JOIN read
pattern (fetch the parent, then
id IN (?, ?, …)for its children) pay for everyid serially, so batching the ids into one query was the slowest available shape
rather than the cheapest.
What it was costing
Measured on a production instance:
/api/services/topology, 24 h windowThe topology number is not a tail — it was 60/60 samples over 500 ms. All of it
was one
id IN (…)carrying one term per turn in the window.It is also not the payload. The same terms with
| stats countand zero rowsreturned still took 12.8 s, while a term-free scan of the same window took
302 ms — i.e. matching ~10 ids by term costs more than scanning everything in
the window. Alternative spellings of the same lookup, same 326-id result:
search … id IN ("a","b",…)← what we emittedsearch … (id="a" OR id="b" …)| where id IN (…)| regex id="^(a|b|…)$"Organic traffic hid all of this: 375 searches over 21 h were p50 46 / p90 94 /
p99 227 ms with zero over 1 s, because nobody had opened the services page.
The change
ID_CHUNK512 → 32, and the three id-keyed reads (read_spans_by_ids,fetch_bodies,endpoints_for_span_ids) run their chunks concurrently insteadof in a
forloop.32 is a measured optimum, not a minimum — at 4 ids per search the per-search
overhead dominates and the bodies lookup regresses to 11.2 s. The full curve is
in the constant's doc comment.
storage.aglake.max_concurrent_searchesstops being accepted-and-ignored andbecomes the bound. It is enforced inside
SearchClient::search, the one methodevery read path goes through, so it caps the total in flight rather than
being a per-query number that k concurrent console requests multiply by k. The
default stays 8, matching aglaked's own default scan pool (
--search-threads 0= half the cores, capped at 8);
default.tomldocuments what 16 buys and that itoversubscribes that pool.
0clamps to 1 — read as "unlimited" it would be azero-permit semaphore and block the first read forever — and is reported by
heron config validate.The session-list fan-out keeps the large chunk (new
FANOUT_ID_CHUNK): itmatches many rows per id rather than one, and its
| head max_sessions_scanbudget is written per search, so splitting the id set would have quietly
multiplied that budget by the chunk count. It was not slow anyway — a 100-session
page measures 293 ms.
Verification
A/B on production data, both binaries against the same daemon and the same
indexes, started and stopped by one script so neither sees different data:
max_concurrent_searches = 16takes the 418-call turn to 2097 ms.Results are unchanged: the 418-span, 418-body response is byte-identical
before and after (sha256 over the canonicalized items), and the topology graph's
nodes and edges compare equal element-for-element.
Tests
concurrency_tests(new, added to the CI step): a mock that records itsown in-flight high-water mark. A semaphore that silently admitted everyone
would pass every other assertion in the suite and fail only these. Verified
they fail without the change — the peak reads 12 instead of the configured 3.
Plus a permit-leak guard: with one permit, a leak on the failure path makes the
next search hang rather than fail.
2 * ID_CHUNK + 1spans. Every existing test used threespans — one chunk — so the split was never taken. Verified both halves fail
without the change: dropping the spans hop's last chunk times out waiting for
rows, and dropping the bodies hop's last chunk loses
span-0032, the first idof the second chunk.
cargo test --workspace: 1236 passed. The aglake suite against a livedaemon: 141 passed. Leakage / secrets / validated-constructor lints clean;
cargo bench --no-runcompiles.Noticed, not fixed
/api/services/topologyreturns its nodes and edges in a nondeterministicorder — four polls of a frozen window give four different orderings, on
mainand on this branch alike (HashMap iteration in
assemble_edges). The content isstable; only the order moves, so the console's service graph reshuffles on every
refresh. Unrelated to this change and left alone.
https://claude.ai/code/session_01GxGWpo3L4BRMkwtoa9X54W