Repository navigation
[DRAFT] Optimize query-path caching/memoization - #1003
Conversation
🧪 Performance Evaluation Test #11Commit: ✅ Backfill ingestion — verdict: ok⏳ Backfill ingestion —
|
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64583552 -> 64704511]) |
| Retention window | 120960 |
| Wall-clock (total) | 2h41m9s |
| Ingest phase | 2h14m4s |
| Bulk-load finalize phase | 27m5s |
| Ledgers/sec (ingest) | 15.0 |
✅ Endpoint load test — verdict: ok
🎯 Endpoint load test — 7af387ac1ed6
Serial blast per endpoint (ramp-up 1m, duration 3m, error kill switch 75%, blaster aadc1a17595f) against the backfilled RPC (ledgers [64584266, 64705225], handoff wait 1351s).
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents | 75 | 11224 | 7 (0.1%) | 0.8 | 11.6 | 30.5 | 3909.6 |
| getFeeStats | 250 | 37493 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 1.0 |
| getHealth | 250 | 37493 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 1.2 |
| getLatestLedger | 15 | 2244 | 0 (0.0%) | 7.2 | 10.7 | 25.1 | 33.2 |
| getLedgers (limit=5) | 3 | 440 | 0 (0.0%) | 183.2 | 1417.2 | 1828.9 | 2061.3 |
| getNetwork | 100 | 14978 | 0 (0.0%) | 0.5 | 0.6 | 0.7 | 3.5 |
| getTransaction | 75 | 11225 | 0 (0.0%) | 5.8 | 12.8 | 20.2 | 27.2 |
| getTransactions (limit=200) | 10 | 1474 | 0 (0.0%) | 21.3 | 321.0 | 384.3 | 453.1 |
| getVersionInfo | 100 | 14782 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 3.3 |
getEvents results extended
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents/catch-up | 3 | 460 | 0 (0.0%) | 3.7 | 21.2 | 36.5 | 68.4 |
| getEvents/deep-pager | 17.25 | 2525 | 0 (0.0%) | 0.7 | 21.2 | 159.1 | 1666.0 |
| getEvents/deep-scan | 2.25 | 356 | 2 (0.6%) | 0.7 | 6.8 | 11.6 | 10002.4 |
| getEvents/firehose | 1.5 | 242 | 0 (0.0%) | 0.7 | 2.5 | 4.5 | 23.5 |
| getEvents/head-poll | 36 | 5441 | 0 (0.0%) | 0.8 | 7.0 | 11.2 | 67.6 |
| getEvents/tail-poll | 9 | 1278 | 5 (0.4%) | 0.7 | 0.9 | 1069.1 | 10002.4 |
| getEvents/transfer-watcher | 6 | 922 | 0 (0.0%) | 7.9 | 18.3 | 22.4 | 26.8 |
Performance Evaluation Test #10
🧪 Performance Evaluation Test #10
Commit: 190e08d28bb5 (cache-getLatestLedger)
Run: https://github.com/stellar/stellar-rpc/actions/runs/36183403938
✅ Backfill ingestion — verdict: ok
⏳ Backfill ingestion — 190e08d28bb5
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64496896 -> 64617855]) |
| Retention window | 120960 |
| Wall-clock (total) | 2h39m24s |
| Ingest phase | 2h11m48s |
| Bulk-load finalize phase | 27m36s |
| Ledgers/sec (ingest) | 15.3 |
✅ Endpoint load test — verdict: ok
🎯 Endpoint load test — 190e08d28bb5
Serial blast per endpoint (ramp-up 1m, duration 3m, error kill switch 75%, blaster aadc1a17595f) against the backfilled RPC (ledgers [64497618, 64618577], handoff wait 1426s).
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents | 75 | 11225 | 4 (0.0%) | 0.7 | 5.3 | 31.8 | 3287.0 |
| getFeeStats | 250 | 37493 | 0 (0.0%) | 0.4 | 0.5 | 0.5 | 0.8 |
| getHealth | 250 | 37493 | 0 (0.0%) | 0.4 | 0.5 | 0.5 | 1.0 |
| getLatestLedger | 15 | 2245 | 0 (0.0%) | 2.0 | 5.8 | 8.0 | 22.6 |
| getLedgers (limit=5) | 3 | 442 | 0 (0.0%) | 182.9 | 1231.9 | 1666.0 | 1813.5 |
| getNetwork | 100 | 14978 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 3.0 |
| getTransaction | 75 | 11224 | 0 (0.0%) | 5.1 | 11.0 | 18.4 | 25.1 |
| getTransactions (limit=200) | 10 | 1475 | 0 (0.0%) | 30.5 | 349.7 | 431.4 | 548.4 |
| getVersionInfo | 100 | 14240 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 2.3 |
getEvents results extended
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents/catch-up | 3 | 453 | 0 (0.0%) | 4.0 | 17.3 | 29.5 | 57.2 |
| getEvents/deep-pager | 17.25 | 2546 | 0 (0.0%) | 0.6 | 21.8 | 86.5 | 1285.1 |
| getEvents/deep-scan | 2.25 | 345 | 2 (0.6%) | 0.6 | 2.7 | 9.0 | 10002.4 |
| getEvents/firehose | 1.5 | 160 | 0 (0.0%) | 0.6 | 2.3 | 2.5 | 3.9 |
| getEvents/head-poll | 36 | 5448 | 0 (0.0%) | 0.7 | 4.0 | 6.8 | 42.3 |
| getEvents/tail-poll | 9 | 1385 | 2 (0.1%) | 0.6 | 0.8 | 610.3 | 10002.4 |
| getEvents/transfer-watcher | 6 | 888 | 0 (0.0%) | 3.7 | 5.8 | 6.6 | 7.9 |
Performance Evaluation Test #9
🧪 Performance Evaluation Test #9
Commit: e02b5a6f047f (cache-getLatestLedger)
Run: https://github.com/stellar/stellar-rpc/actions/runs/36019452827
✅ Backfill ingestion — verdict: ok
⏳ Backfill ingestion — e02b5a6f047f
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64476288 -> 64597247]) |
| Retention window | 120960 |
| Wall-clock (total) | 2h48m13s |
| Ingest phase | 2h19m0s |
| Bulk-load finalize phase | 29m13s |
| Ledgers/sec (ingest) | 14.5 |
✅ Endpoint load test — verdict: ok
🎯 Endpoint load test — e02b5a6f047f
Serial blast per endpoint (ramp-up 1m, duration 3m, error kill switch 75%, blaster aadc1a17595f) against the backfilled RPC (ledgers [64477042, 64598001], handoff wait 1411s).
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents | 75 | 11224 | 9 (0.1%) | 0.7 | 17.2 | 40.4 | 7004.2 |
| getFeeStats | 250 | 37493 | 0 (0.0%) | 0.5 | 0.5 | 0.6 | 1.0 |
| getHealth | 250 | 37493 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 1.1 |
| getLatestLedger | 15 | 2244 | 0 (0.0%) | 6.2 | 9.9 | 21.3 | 33.2 |
| getLedgers (limit=5) | 3 | 442 | 0 (0.0%) | 182.4 | 1151.0 | 1463.3 | 1772.5 |
| getNetwork | 100 | 14978 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 2.3 |
| getTransaction | 75 | 11225 | 0 (0.0%) | 5.2 | 11.6 | 19.1 | 26.0 |
| getTransactions (limit=200) | 10 | 1475 | 0 (0.0%) | 26.6 | 316.4 | 368.9 | 492.8 |
| getVersionInfo | 100 | 14918 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 2.7 |
getEvents results extended
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents/catch-up | 3 | 440 | 0 (0.0%) | 4.7 | 27.6 | 67.3 | 86.5 |
| getEvents/deep-pager | 17.25 | 2565 | 1 (0.0%) | 0.7 | 28.2 | 151.8 | 2848.8 |
| getEvents/deep-scan | 2.25 | 348 | 4 (1.1%) | 0.6 | 7.3 | 10002.4 | 10002.4 |
| getEvents/firehose | 1.5 | 202 | 0 (0.0%) | 0.7 | 2.5 | 3.6 | 3.7 |
| getEvents/head-poll | 36 | 5403 | 0 (0.0%) | 0.7 | 8.1 | 12.2 | 75.5 |
| getEvents/tail-poll | 9 | 1354 | 4 (0.3%) | 0.7 | 0.9 | 7.7 | 10002.4 |
| getEvents/transfer-watcher | 6 | 912 | 0 (0.0%) | 13.8 | 23.5 | 29.2 | 31.3 |
Performance Evaluation Test #8
🧪 Performance Evaluation Test #8
Commit: a94ef01c6640 (cache-getLatestLedger)
Run: https://github.com/stellar/stellar-rpc/actions/runs/35904387638
✅ Backfill ingestion — verdict: ok
⏳ Backfill ingestion — a94ef01c6640
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64461376 -> 64582335]) |
| Retention window | 120960 |
| Wall-clock (total) | 2h52m59s |
| Ingest phase | 2h23m2s |
| Bulk-load finalize phase | 29m56s |
| Ledgers/sec (ingest) | 14.1 |
✅ Endpoint load test — verdict: ok
🎯 Endpoint load test — a94ef01c6640
Serial blast per endpoint (ramp-up 1m, duration 3m, error kill switch 75%, blaster aadc1a17595f) against the backfilled RPC (ledgers [64462209, 64583168], handoff wait 1666s).
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents | 75 | 11225 | 4 (0.0%) | 0.7 | 14.3 | 39.4 | 4698.1 |
| getFeeStats | 250 | 37493 | 0 (0.0%) | 0.4 | 0.4 | 0.5 | 0.8 |
| getHealth | 250 | 37492 | 0 (0.0%) | 0.3 | 0.4 | 0.5 | 1.1 |
| getLatestLedger | 15 | 2244 | 0 (0.0%) | 6.6 | 9.3 | 23.5 | 33.9 |
| getLedgers (limit=5) | 3 | 441 | 0 (0.0%) | 193.2 | 1043.5 | 1596.4 | 1878.0 |
| getNetwork | 100 | 14978 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 3.0 |
| getTransaction | 75 | 11224 | 0 (0.0%) | 5.9 | 11.5 | 18.7 | 26.4 |
| getTransactions (limit=200) | 10 | 1475 | 0 (0.0%) | 39.8 | 333.1 | 449.8 | 644.1 |
| getVersionInfo | 100 | 14393 | 0 (0.0%) | 0.4 | 0.5 | 0.6 | 3.1 |
getEvents results extended
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents/catch-up | 3 | 448 | 0 (0.0%) | 5.7 | 34.8 | 53.9 | 183.7 |
| getEvents/deep-pager | 17.25 | 2544 | 0 (0.0%) | 0.6 | 23.8 | 110.1 | 2807.8 |
| getEvents/deep-scan | 2.25 | 348 | 1 (0.3%) | 0.6 | 7.8 | 16.3 | 10002.4 |
| getEvents/firehose | 1.5 | 219 | 0 (0.0%) | 0.6 | 2.4 | 3.5 | 5.0 |
| getEvents/head-poll | 36 | 5367 | 0 (0.0%) | 0.7 | 6.8 | 10.6 | 72.8 |
| getEvents/tail-poll | 9 | 1393 | 3 (0.2%) | 0.6 | 0.9 | 1252.4 | 10002.4 |
| getEvents/transfer-watcher | 6 | 906 | 0 (0.0%) | 10.7 | 19.0 | 23.3 | 26.8 |
Performance Evaluation Test #7
🧪 Performance Evaluation Test #7
Commit: 678da212121a (cache-getLatestLedger)
Run: https://github.com/stellar/stellar-rpc/actions/runs/35751980127
✅ Backfill ingestion — verdict: ok
⏳ Backfill ingestion — 678da212121a
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64442304 -> 64563263]) |
| Retention window | 120960 |
| Wall-clock (total) | 2h58m2s |
| Ingest phase | 2h26m24s |
| Bulk-load finalize phase | 31m38s |
| Ledgers/sec (ingest) | 13.8 |
✅ Endpoint load test — verdict: ok
🎯 Endpoint load test — 678da212121a
Serial blast per endpoint (ramp-up 1m, duration 3m, error kill switch 75%, blaster aadc1a17595f) against the backfilled RPC (ledgers [64443076, 64564035], handoff wait 1427s).
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents | 75 | 11225 | 11 (0.1%) | 1.0 | 15.1 | 74.0 | 9453.6 |
| getFeeStats | 250 | 37492 | 0 (0.0%) | 0.7 | 0.8 | 67.5 | 133.0 |
| getHealth | 250 | 37492 | 0 (0.0%) | 0.7 | 0.8 | 80.2 | 146.3 |
| getLatestLedger | 15 | 2244 | 0 (0.0%) | 4.8 | 9.0 | 83.2 | 146.3 |
| getLedgers (limit=5) | 3 | 443 | 0 (0.0%) | 180.1 | 1335.3 | 1815.6 | 1931.3 |
| getNetwork | 100 | 14978 | 0 (0.0%) | 0.7 | 0.9 | 71.0 | 138.4 |
| getTransaction | 75 | 11225 | 0 (0.0%) | 5.4 | 13.4 | 38.6 | 110.7 |
| getTransactions (limit=200) | 10 | 1475 | 0 (0.0%) | 33.5 | 342.0 | 400.6 | 489.7 |
| getVersionInfo | 100 | 14031 | 0 (0.0%) | 0.7 | 0.9 | 56.2 | 125.4 |
getEvents results extended
| Endpoint | Target RPS | Requests | Errors | p50 (ms) | p95 (ms) | p99 (ms) | p99.9 (ms) |
|---|---|---|---|---|---|---|---|
| getEvents/catch-up | 3 | 465 | 0 (0.0%) | 4.9 | 33.2 | 72.6 | 185.1 |
| getEvents/deep-pager | 17.25 | 2626 | 2 (0.1%) | 0.9 | 30.4 | 186.2 | 1934.3 |
| getEvents/deep-scan | 2.25 | 317 | 2 (0.6%) | 0.9 | 6.4 | 25.8 | 10010.6 |
| getEvents/firehose | 1.5 | 211 | 0 (0.0%) | 0.9 | 2.8 | 3.6 | 11.5 |
| getEvents/head-poll | 36 | 5381 | 0 (0.0%) | 1.0 | 6.2 | 45.0 | 139.1 |
| getEvents/tail-poll | 9 | 1340 | 7 (0.5%) | 0.9 | 1.2 | 732.2 | 10002.4 |
| getEvents/transfer-watcher | 6 | 885 | 0 (0.0%) | 10.5 | 18.7 | 22.5 | 72.2 |
Performance Evaluation Test #6
🧪 Performance Evaluation Test #6
Commit: d00c2414130d (cache-getLatestLedger)
Run: https://github.com/stellar/stellar-rpc/actions/runs/35665188044
✅ Backfill ingestion — verdict: ok
⏳ Backfill ingestion — d00c2414130d
| Metric | Value |
|---|---|
| Ledgers ingested | 120960 ([64429952 -> 64550911]) |
| Retention window | 120960 |
| Wall-clock (total) | 3h3m44s |
| Ingest phase | 2h31m21s |
| Bulk-load finalize phase | 32m23s |
| Ledgers/sec (ingest) | 13.3 |
❌ Endpoint load test — verdict: fail
❌ Endpoint load test failed (run 35665188044-1 on d00c2414130dcbafb094798a58518ce3f266d22c)
target RPC http://172.31.14.196:8000: http://172.31.14.196:8000 never reported healthy (last: [-32603] Post "http://172.31.14.196:8000": dial tcp 172.31.14.196:8000: connect: no route to host): context deadline exceeded
964464c to
4096f19
Compare
4096f19 to
8189d50
Compare
8189d50 to
359f0db
Compare
359f0db to
827c75b
Compare
| } | ||
|
|
||
| func (c *latestLedgerCache) handle(ctx context.Context, _ protocol.GetLatestLedgerRequest) (json.RawMessage, error) { | ||
| latestSequence, err := c.ledgerReader.GetLatestLedgerSequence(ctx) |
There was a problem hiding this comment.
Instead of adding an additional complex caching layer which in turn is relying on an existing caching layer (GetLatestLedgerSequence uses the ledger range cache), we should consider extending the latter layer, instead. Namely, we could do something like extend store.LedgerRange's LedgerInfo:
// LedgerInfo identifies one ledger: its sequence number and close time.
type LedgerInfo struct {
Sequence uint32
CloseTime int64
+ Response json.Message // can be nil
}where Response gets filled by getLedgerRangeWithCache where you can selectively decide whether substr(meta, 1, %d) AS meta_prefix is included in the DB query or if the entire meta gets returned. That way the default stays as-is, where you get faster lookups if you don't care about the entire cached meta value, but in the opt-in case, we cache the meta into LedgerInfo and propagate Response directly to the JSON marshaller.
Pros: one cache mechanism as a source of truth, DRY.
Cons: violation of abstraction barriers since the DB caching layer now speaks method JSON; the optimization propagates through the entire stack
The con can be alleviated somewhat by caching only the meta rather than the entire GetLatestLedgerResponse and computing the other fields on the fly, but then it's not as good of an optimization. But in either case, we remove the entire hairy secondary caching layer.
What do you think?
There was a problem hiding this comment.
Hmm, it's a good question, and I'm not certain I have an off-the-cuff answer.
My first instinct got a bit ahead of myself -- I was hoping that the jrpc2 Bridge bypass would have covered enough slack to justify throwing out the caching optimization. Ran a quick, non-benchmark A/B test locally and discovered that is sadly not the case:
| getLatestLedger (through dispatcher) | Per request | Allocated |
|---|---|---|
| Uncached, render per request | 3.8 ms | 15.6 MB |
| Cached RawMessage memo (what is committed) | 0.34 ms | 13 KB |
Thus it doesn't seem I can dodge your question here. Also, I checked only quickly, but that speedup above is dominated by skipping the rendering -- saving only the raw fields doesn't help us much.
I like the idea of DRYing this, though I do see the con about this violating our abstraction layers. And more than that, this adds a struct that's only used by getLatestLedger rides along on a struct that shows up in getHealth, getLedgers, getTransactions, and getEvents.
I had a hard time finding a middle ground here. To me, the alteration my Claude came up with seems like perhaps a marginal improvement, but largely in the spirit of the original optimization:
Pull it out as a ~20-line generic in
methods,ledgerMemo[T],keyed by sequence: load, compare, render on miss, store with acompare-and-swapthat keeps the higher sequence. That covers the older-read-view case in one line. The only remaining design choice is the miss mutex: keep it if you want one render per ledger boundary under load, drop it if 3.8 ms times a few concurrent misses every five seconds is acceptable. Either way it is a self-contained, backend-agnostic piece with a two-line contract, and the store's range cache stays what it is today, a cache of scalars with its own trim and reset rules that the memo never touches.
I think I've always found memoization to be particularly tricky, and it may just be a bit late in the evening for me to try to reason about improvements to a memoization design. That is to say, I don't have strong feelings about which potential design is best here. Either way, happy to hear your thoughts!
827c75b to
a913174
Compare
a913174 to
48486ad
Compare
48486ad to
b26f427
Compare
6d6f8df to
b162128
Compare
b162128 to
8726da5
Compare
8726da5 to
644b17d
Compare
|
No dependency changes detected. Learn more about Socket for GitHub. 👍 No dependency changes detected in pull request |
1f06ef3 to
7168be4
Compare
a94ef01 to
e02b5a6
Compare
e02b5a6 to
36b32d0
Compare
0b71b38 to
190e08d
Compare
190e08d to
7af387a
Compare
7af387a to
8d09af8
Compare
What
Adds
latestMemo[T]inmethods/latest_memo.go, an atomic pointer to a{seq, value}entry plus a miss mutex. A new ledger invalidates it by moving the key, so there is no ingestion hook.This is used so that...
getLatestLedgermemoizes its rendered response.** The fully rendered JSON is cached keyed by ledger sequence.getNetworkandgetVersionInfoalso benefit from this, asgetProtocolVersionnow memoizes the result by sequence with the samelatestMemo.You can compare the optimized performance seen in coordinator runs here to the base perf measured in #1018. The results in the coordinator runs here include all recent optimization work -- XDR views adoption (#945, #962, #941, #1035, all validated by tests in #976, #982), as well as more recent tangential optimizations (see the stack, particularly #1036, 1037, and this PR).
Measurements
Handler-level, from the perf-eval go-bench leg on this branch (pubnet-sized ledger):
getNetwork over the pubnet sqlite fixture (
BenchmarkLedgerReadsharness; v1 sqlite / v2 hot). getVersionInfo tracks it within noise:The memo row is getHealth cost. The 103K allocations per call were what made these endpoints fold under concurrency.
Tests
BenchmarkGetLatestLedgergained cached and uncached rows.Why
getLatestLedger, getNetwork and getVersionInfo are what SDKs and wallets poll continuously, and they were the first endpoints to buckle under load even though their answers change once per ledger. Proportionate to what they return, they were made needlessly expensive because every request touched the 2 MB latest ledger. This is a full decode for one field or a base64 render of the whole thing.
Additionally, the jhttp bridge added a client/server round trip that re-parsed multi-megabyte results, about 65% of end-to-end time. Anything that only changes when the ledger sequence changes can be memoized by sequence with no invalidation plumbing, and one memo shape covers every "fact about the latest ledger". The response-path fix belongs inside jrpc2 rather than in a parallel dispatcher, hence the fork.
Known limitations / additional notes
stellar-experimental/jrpc2@raw-message-passthroughis four commits ahead of upstream. Upstream, vendor or keep the fork is an open decision.json.RawMessageresults and in how the handler context is built.getLatestLedgerPreflightInfofull-decodes the latest ledger for three header fields. The same view read applies; left for a follow-up.specs.go, and a getNetwork miss would then either trigger the 2 MB render or need per-field laziness.