Skip to content

perf(aglake): id lookups fan out, because every search term costs the same - #200

Open
vaderyang wants to merge 2 commits into
mainfrom
perf/aglake-concurrent-id-lookups
Open

perf(aglake): id lookups fan out, because every search term costs the same#200
vaderyang wants to merge 2 commits into
mainfrom
perf/aglake-concurrent-id-lookups

Conversation

@vaderyang

Copy link
Copy Markdown
Collaborator

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 every
id 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:

opening a 418-call agent turn 14.6 s
/api/services/topology, 24 h window 7.5 s, on every call

The 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 count and zero rows
returned 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:

shape ms
search … id IN ("a","b",…) ← what we emitted 6694
search … (id="a" OR id="b" …) 6282
| where id IN (…) 773
| regex id="^(a|b|…)$" 121
full window scan, filter in Rust 143

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_CHUNK 512 → 32, and the three id-keyed reads (read_spans_by_ids,
fetch_bodies, endpoints_for_span_ids) run their chunks concurrently instead
of in a for loop.

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_searches stops being accepted-and-ignored and
becomes the bound. It is enforced inside SearchClient::search, the one method
every 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.toml documents what 16 buys and that it
oversubscribes that pool. 0 clamps to 1 — read as "unlimited" it would be a
zero-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): 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 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:

endpoint before after
a 418-call turn 14576 ms 2586 ms 5.6×
services topology, 24 h 7525 ms 1722 ms 4.4×
a 60-call turn 1121 ms 681 ms 1.6×
a 5-call turn 231 ms 236 ms one chunk either way
spans / traces lists, sessions, metrics within noise

max_concurrent_searches = 16 takes 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 its
    own 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.
  • A live turn of 2 * ID_CHUNK + 1 spans. Every existing test used three
    spans — 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 id
    of the second chunk.
  • cargo test --workspace: 1236 passed. The aglake suite against a live
    daemon: 141 passed. Leakage / secrets / validated-constructor lints clean;
    cargo bench --no-run compiles.

Noticed, not fixed

/api/services/topology returns its nodes and edges in a nondeterministic
order — four polls of a frozen window give four different orderings, on main
and on this branch alike (HashMap iteration in assemble_edges). The content is
stable; 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

… 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

@github-actions github-actions Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggestions

  • server/h-storage-aglake/src/client.rs:810 — Tokio's Semaphore::acquire is fair (FIFO), and the three fan-out sites now hand every chunk to search() in one try_join_all. With ID_CHUNK = 32 a 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. Consider acquire_many/a per-caller bound, or at minimum note the convoy in AglakeConfig::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_CHUNK at 32 rather than 512, the None-window path (query_spans_by_ids, ids from the in-memory registry) now runs up to 2 chunks' worth of fetch_raw_by_id retries 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 that query_spans_by_ids didn't regress; the new it.rs test covers the ordering, not the miss cost.

  • server/h-storage-aglake/src/services.rs:462endpoints_for_span_ids fans out over MAX_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 | head budget 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. The spl.rs doc 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 0 check is emitted inside if self.storage.backend == AGLAKE_BACKEND, which matches the sibling AglakePasswordWithoutUsername and the doc comment says so explicitly. But SearchClient::new clamps max(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:2344a_failed_search_returns_its_permit builds its own AglakeConfig literal rather than reusing the CountingAglake::config helper, so it duplicates four fields. Folding FailingAglake into the same helper shape would keep the two mocks from drifting.

Questions

  • The commit message says "drop --search-threads" nowhere but default.toml:189 tells operators to "raise --search-threads alongside it on a search-heavy box." Is max_concurrent_searches = 8 deliberately pinned to aglaked's default scan pool so that raising it is opt-in, and if so, should config validate warn 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:23 and spl.rs:286 both cite ID_CHUNK 512 → 32, but the table at spl.rs:274–279 measures 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 answers 500 with a body of {"error":"boom"}. Does describe_search_failure (client.rs:858) hit the _ arm for a 500, and does the retry logic in WriteBuffer/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 pub surface change is AglakeZeroConcurrentSearches, a ConfigIssue variant, which is not mirrored in console/src/types/api.ts (that file carries no config-issue type).
  • ConfigIssue exhaustiveness: severity() (config.rs:1359) and Display (config.rs:1502) both add arms; the two consumers (cmd/validate.rs, cmd/doctor.rs) match on severity()/to_string(), not on the enum, so no non-exhaustive match breaks.
  • Version SSOT: VERSION, server/Cargo.toml:11, and console/package.json all read 0.8.1; Cargo.lock bump to 0.8.1 matches. No version drift introduced.
  • futures wiring: server/Cargo.toml:33 adds it to workspace.dependencies, h-pcap-extract/Cargo.toml:14 converts its direct dep to .workspace = true, h-storage-aglake/Cargo.toml:16 adds it. Both crates' existing futures:: usages (pcap-extract StreamExt/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), or LENGTH(body) in the diff; the two DuckDB hits at metrics.rs:848/1070 are pre-existing and outside this change.
  • ConfigIssue 0-clamp test: config.rs:3007 asserts the variant fires for 0 and stays silent for 1 and the default — matches the runtime clamp at client.rs:793.

Agent output was missing required heading.


🤖 Reviewed by the review botworkflow 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
@vaderyang

Copy link
Copy Markdown
Collaborator Author

Upstream fixed the cost this branch was measured against, so I re-derived the
constant against a daemon carrying the fix. ID_CHUNK is now 64, not 32
(bb14d54). The fan-out itself stands — that was the live question and the answer
is no, the fix does not make it redundant.

What upstream changed

The per-term cost on dictionary-less (unsealed) buckets was quadratic per event:
three linear scans in the residual lookup structures, none of which
short-circuited on a miss. It is now index lookups. Worth ~4× on its own.

Worth stating that no released build has it yet — the newest published nightly
predates the fix, and measures identical to the version in production (1.0×
across a term sweep on the same data). I built from source at the fixing commit
to get these numbers.

Re-derived: 400 span ids against a hot bucket, 8 permits, 5 interleaved reps

chunk searches production's daemon with the fix
400 (one search) 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 builds and the optimum is sharp in both directions: fewer,
bigger searches leave the permits idle, and more, smaller ones pay the
per-search overhead more times than the terms save. 32 was costing 1.19× the
optimum on the unfixed daemon and 1.45× 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 that 13% "within
noise across the three hops" and took the compromise. It was not noise.

The fan-out is not redundant after the fix

Still 3.5× faster than one search, 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 × 64 ids also resolves up to 512 ids in one wave, which
covers every turn observed so far.

Verification

Built aglaked from source at the fixing commit and A/B'd it against the version
in production, each on its own copy of the same real index, ingesting identical
events so both had a genuine hot bucket. Interleaved reps rather than one build
then the other, so drift on the box cannot be attributed to a build.

Workspace 1236 passed; the live suite 141 passed against a current daemon build.

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.

1 participant