Skip to content

Commit 40d3c92

Browse files
authored
feat(pxe): constrained tag sync optimization and recipient logs sync benchmarks (#24275)
Fixes [F-704](https://linear.app/aztec-labs/issue/F-704/optimize-constrained-tag-sync) ## Summary Constrained delivery emits a gapless tagging-index stream, so PXE can stop scanning at the first missing constrained tag instead of probing the full unfinalized window on every sync. This PR: - Starts constrained scans with a small probe and **doubles** the probe size while every probed index has a log, capped at the existing window. - Keeps steady-state polling cheap: one tag per constrained secret. - Reduces catch-up round-trips geometrically until the probe reaches the window cap. - Decouples probe advancement from finalized-cursor persistence so unfinalized logs are still fetched without persisting unsafe cursors. - Leaves unconstrained sync and `findHighestIndexes` unchanged. ## Benchmarks Benchmarks compare doubling against fixed-size probes. The takeaway is that doubling preserves the steady-state tag-query floor of `P=1` while avoiding `P=1`'s one-round-trip-per-log catch-up behavior. A sync runs in rounds: each round computes the next batch of tags, sends them to the node, and blocks on the result before deciding the next round. All counts are per sync. - **tag-queries** — total tags looked up on the node. - **round-trips** — sequential client waits. A round's tags are chunked into parallel calls internally, so a wide round is still one round-trip. - **blocking-ms** — measured wall-clock the caller spends blocked on the node with modeled node latency. This is reported only and varies run to run. Scenarios seed a recipient that already synced prior messages, then measure the next single sync. `secrets = N` means N independent sender streams synced together in one batched pass. - **steady-state** — no new logs since the last sync. - **catch-up-K** — K new contiguous logs per secret since the last sync. - **mixed** — 999 idle secrets plus 1 deep straggler (`K=100`) at 1,000 secrets. ### Cost per sync: doubling vs fixed-P alternatives **doubling is the shipped policy.** The fixed-P columns are the selection comparison that motivated it: `P=84` is the current full-window behavior, and `P=1..5` sweep the constant-step alternative. Unconstrained is not shown as its own row: its windowed scan cannot first-miss, so it is invariant to P and reproduces the `P=84` column. **Tag-queries (thousands)** (exact count = value x 1,000; bold = fewest among the fixed-P columns; `doubling (init=1)` is the shipped policy, `doubling (init=2)`/`doubling (init=4)` start the probe at 2/4 instead of 1): | scenario | doubling (init=1) | doubling (init=2) | doubling (init=4) | P=1 | P=2 | P=3 | P=4 | P=5 | P=84 | |---|---|---|---|---|---|---|---|---|---| | steady, 100 | 0.1 | 0.2 | 0.4 | **0.1** | 0.2 | 0.3 | 0.4 | 0.5 | 8.4 | | steady, 1,000 | 1 | 2 | 4 | **1** | 2 | 3 | 4 | 5 | 84 | | catch-up-1, 100 | 0.3 | 0.2 | 0.4 | **0.2** | 0.2 | 0.3 | 0.4 | 0.5 | 8.4 | | catch-up-1, 1,000 | 3 | 2 | 4 | **2** | 2 | 3 | 4 | 5 | 84 | | catch-up-3, 100 | 0.7 | 0.6 | 0.4 | **0.4** | 0.4 | 0.6 | 0.4 | 0.5 | 8.4 | | catch-up-3, 1,000 | 7 | 6 | 4 | **4** | 4 | 6 | 4 | 5 | 84 | | catch-up-84, 100 | 12.7 | 12.6 | 12.4 | **8.5** | 8.6 | 8.7 | 8.8 | 8.5 | 16.8 | | catch-up-84, 1,000 | 127 | 126 | 124 | **85** | 86 | 87 | 88 | 85 | 168 | | catch-up-50, 100 | 6.3 | 6.2 | 6 | **5.1** | 5.2 | 5.1 | 5.2 | 5.5 | 8.4 | | catch-up-50, 1,000 | 63 | 62 | 60 | **51** | 52 | 51 | 52 | 55 | 84 | | catch-up-100, 100 | 12.7 | 12.6 | 12.4 | **10.1** | 10.2 | 10.2 | 10.4 | 10.5 | 16.8 | | catch-up-100, 1,000 | 127 | 126 | 124 | **101** | 102 | 102 | 104 | 105 | 168 | | mixed, 1,000 (999 idle + 1 deep K=100) | 1.126 | 2.124 | 4.12 | **1.1** | 2.1 | 3.099 | 4.1 | 5.1 | 84.084 | **Round-trips** (bold = fewest among the fixed-P columns; `doubling (init=1)` is the shipped policy, `doubling (init=2)`/`doubling (init=4)` start the probe at 2/4 instead of 1): | scenario | doubling (init=1) | doubling (init=2) | doubling (init=4) | P=1 | P=2 | P=3 | P=4 | P=5 | P=84 | |---|---|---|---|---|---|---|---|---|---| | steady, 100 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | | steady, 1,000 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | 1 | | catch-up-1, 100 | 2 | 1 | 1 | 2 | **1** | 1 | 1 | 1 | 1 | | catch-up-1, 1,000 | 2 | 1 | 1 | 2 | **1** | 1 | 1 | 1 | 1 | | catch-up-3, 100 | 3 | 2 | 1 | 4 | 2 | 2 | **1** | 1 | 1 | | catch-up-3, 1,000 | 3 | 2 | 1 | 4 | 2 | 2 | **1** | 1 | 1 | | catch-up-84, 100 | 7 | 6 | 5 | 85 | 43 | 29 | 22 | 17 | **2** | | catch-up-84, 1,000 | 7 | 6 | 5 | 85 | 43 | 29 | 22 | 17 | **2** | | catch-up-50, 100 | 6 | 5 | 4 | 51 | 26 | 17 | 13 | 11 | **1** | | catch-up-50, 1,000 | 6 | 5 | 4 | 51 | 26 | 17 | 13 | 11 | **1** | | catch-up-100, 100 | 7 | 6 | 5 | 101 | 51 | 34 | 26 | 21 | **2** | | catch-up-100, 1,000 | 7 | 6 | 5 | 101 | 51 | 34 | 26 | 21 | **2** | | mixed, 1,000 (999 idle + 1 deep K=100) | 7 | 6 | 5 | 101 | 51 | 34 | 26 | 21 | **2** | **Blocking wall-clock (ms)** (reported only, noisy; the three `doubling` columns are from one paired re-run, the fixed-P columns from the earlier comparison sweep, so not every column is from a single run): | scenario | doubling (init=1) | doubling (init=2) | doubling (init=4) | P=1 | P=2 | P=3 | P=4 | P=5 | P=84 | |---|---|---|---|---|---|---|---|---|---| | steady, 100 | 6 | 6 | 6 | 6 | 6 | 6 | 6 | 6 | 8 | | steady, 1,000 | 6 | 7 | 7 | 7 | 5 | 7 | 7 | 8 | 21 | | catch-up-1, 100 | 14 | 8 | 8 | 13 | 8 | 8 | 8 | 8 | 12 | | catch-up-1, 1,000 | 32 | 28 | 31 | 32 | 27 | 29 | 31 | 28 | 54 | | catch-up-3, 100 | 23 | 18 | 13 | 29 | 18 | 18 | 12 | 12 | 15 | | catch-up-3, 1,000 | 77 | 77 | 71 | 83 | 73 | 79 | 64 | 67 | 95 | | catch-up-84, 100 | 207 | 215 | 211 | 663 | 407 | 335 | 321 | 265 | 205 | | catch-up-84, 1,000 | 1,886 | 1,893 | 1,986 | 2,226 | 1,942 | 1,935 | 1,871 | 1,830 | 2,000 | | catch-up-50, 100 | 132 | 132 | 132 | 397 | 243 | 193 | 171 | 161 | 127 | | catch-up-50, 1,000 | 1,162 | 1,167 | 1,193 | 1,307 | 1,169 | 1,191 | 1,114 | 1,108 | 1,217 | | catch-up-100, 100 | 244 | 244 | 260 | 784 | 480 | 396 | 348 | 321 | 245 | | catch-up-100, 1,000 | 2,242 | 2,265 | 2,361 | 2,632 | 2,348 | 2,341 | 2,212 | 2,236 | 2,366 | | mixed, 1,000 (999 idle + 1 deep K=100) | 43 | 37 | 31 | 590 | 296 | 199 | 150 | 124 | 32 | ### Takeaway `P=1` is the tag-query floor, but it pays one round-trip per new log during catch-up. The full window (`P=84`) minimizes catch-up round-trips, but it charges every idle secret the full-window tag cost on every sync. Doubling is the middle ground: it matches `P=1` at steady state, stays close to `P=1` on tag queries during catch-up, and collapses deep catch-up round-trips geometrically. In the mixed scenario, doubling uses 1,126 tag queries vs 1,100 for `P=1`, but needs 7 round-trips instead of 101; compared with `P=84`, it avoids the 84,084-tag idle tax while staying within 5 round-trips of the full-window catch-up path. ## Testing - Unit tests cover scan shape, doubling behavior, batched-round semantics, and returned-log equivalence. - Benchmark tests report tag queries, round-trips, and modeled blocking time for steady-state, catch-up, mixed, and unconstrained scenarios.
1 parent 6a70be2 commit 40d3c92

7 files changed

Lines changed: 797 additions & 331 deletions

File tree

yarn-project/pxe/src/tagging/constants.ts

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,3 +18,13 @@ import { MAX_PRIVATE_LOGS_PER_TX } from '@aztec/constants';
1818
// reserved at log emission time, before squashing is decided, and the kernel's reset/squash loop is not bounded by
1919
// MAX_PRIVATE_LOGS_PER_TX. No fixed window value closes that gap.
2020
export const UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN = MAX_PRIVATE_LOGS_PER_TX + 20;
21+
22+
// The number of tags probed per constrained secret in the first round.
23+
//
24+
// The probe doubles each round (2, 4, 8, ..., capped at UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN) while every probed
25+
// index is a hit, stopping at the first missing tag. Constrained delivery is gapless, so a single missing tag proves
26+
// the stream has ended: at steady state this turns a full WINDOW_LEN probe into two tags. A secret K logs behind
27+
// catches up in ~log2(K) round-trips while the probe is still doubling (2, 4, 8, 16, 32), but once it saturates the cap
28+
// and advances WINDOW_LEN tags per round, deeper catch-up is linear at ~K/WINDOW_LEN rounds. Either way it beats both
29+
// the full window every round and one round per log.
30+
export const INITIAL_CONSTRAINED_PROBE_LEN = 2;

yarn-project/pxe/src/tagging/index.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@
1212
export { syncTaggedPrivateLogs } from './recipient_sync/sync_tagged_private_logs.js';
1313
export { syncSenderTaggingIndexes } from './sender_sync/sync_sender_tagging_indexes.js';
1414
export { persistSenderTaggingIndexRangesForTx } from './persist_sender_tagging_index_ranges.js';
15-
export { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN } from './constants.js';
15+
export { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, INITIAL_CONSTRAINED_PROBE_LEN } from './constants.js';
1616
export { getAllPrivateLogsByTags, getAllPublicLogsByTagsFromContract } from './get_all_logs_by_tags.js';
1717

1818
// Re-export tagging-related types from stdlib
Lines changed: 267 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,267 @@
1+
import { MAX_TX_LIFETIME } from '@aztec/constants';
2+
import { BlockNumber } from '@aztec/foundation/branded-types';
3+
import { sum, times } from '@aztec/foundation/collection';
4+
import { createLogger } from '@aztec/foundation/log';
5+
import { sleep } from '@aztec/foundation/sleep';
6+
import { openTmpStore } from '@aztec/kv-store/lmdb-v2';
7+
import type { AztecNode } from '@aztec/stdlib/interfaces/server';
8+
import { AppTaggingSecretKind, type PrivateLogsQuery, randomLogResult } from '@aztec/stdlib/logs';
9+
import { randomAppTaggingSecret } from '@aztec/stdlib/testing';
10+
import { BlockHeader } from '@aztec/stdlib/tx';
11+
12+
import { mkdir, writeFile } from 'fs/promises';
13+
import { type MockProxy, mock } from 'jest-mock-extended';
14+
import path from 'path';
15+
16+
import { BenchmarkedNodeFactory } from '../../contract_function_simulator/benchmarked_node.js';
17+
import { RecipientTaggingStore } from '../../storage/tagging_store/recipient_tagging_store.js';
18+
import { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, syncTaggedPrivateLogs } from '../index.js';
19+
import { computeSiloedTagForIndex, extractTags } from '../testing/tag_query_test_utils.js';
20+
21+
/**
22+
* Benchmark for constrained recipient tag-sync.
23+
*
24+
* Measures the per-sync cost of `syncTaggedPrivateLogs` for constrained secrets. Constrained streams are gapless, so
25+
* the scan uses a doubling first-miss probe (see `INITIAL_CONSTRAINED_PROBE_LEN` in `../constants.ts` for the probe
26+
* schedule and complexity analysis), stopping at the first missing tag instead of fetching the full window. This only
27+
* reports costs; the scan behavior itself (probe schedules, round counts) is pinned by the unit tests in
28+
* `sync_tagged_private_logs.test.ts`, which run in CI while this bench is opt-in.
29+
*
30+
* Manual run:
31+
* ```bash
32+
* RUN_TAG_SYNC_BENCH=1 JEST_MAX_WORKERS=1 BENCH_OUTPUT=/tmp/tag-sync-bench-current.json \
33+
* yarn workspace @aztec/pxe test src/tagging/recipient_sync/sync_tagged_private_logs.bench.test.ts
34+
* ```
35+
*
36+
* Metrics, per scenario:
37+
* - `tag-queries`: total tags queried, the throughput win.
38+
* - `rpc-round-trips`: sequential blocking waits on the node, via `BenchmarkedNodeFactory`. The latency axis: this
39+
* grows with K per the complexity analysis on `INITIAL_CONSTRAINED_PROBE_LEN`, and depends only on K, not on secret
40+
* count. A round's tags are chunked at MAX_RPC_LEN (=100) into parallel calls internally, but those overlap, so a
41+
* wide round is still one round-trip; that is why round-trips, not raw call count, is the latency axis.
42+
* - `rpc-blocking-time`: measured wall-clock the caller blocks on the node, under a modeled
43+
* `MODELED_NODE_RPC_LATENCY_MS` per call plus a little per-round overhead. Parallel calls within a round overlap, so
44+
* it tracks round-trips (a 1000-secret round is many parallel chunks but ~one round-trip of blocking time).
45+
*
46+
* Scenario labels: `steady-state` is no new logs (K = 0); `catch-up-K` is K new contiguous logs per secret since the
47+
* last sync; `secrets=N` is N secrets synced together in one batched pass. Because round-trips depend only on K (not
48+
* N), the light catch-up scenarios run at both 100 and 1000 secrets to show tag-queries scale with N while round-trips
49+
* do not. The `mixed` row is the realistic active sync (999 idle secrets + 1 deep straggler at K = 100): it isolates
50+
* that tag-queries stay dominated by the idle majority while a single straggler alone sets the round-trip count.
51+
*/
52+
53+
const logger = createLogger('pxe:tagging:bench');
54+
55+
const FINALIZED_BLOCK_NUMBER = BlockNumber(10);
56+
const ANCHOR_BLOCK_NUMBER = BlockNumber(100);
57+
const CURRENT_TIMESTAMP = BigInt(Math.floor(Date.now() / 1000));
58+
const ANCHOR_BLOCK_HEADER = BlockHeader.random({ blockNumber: ANCHOR_BLOCK_NUMBER, timestamp: CURRENT_TIMESTAMP });
59+
const AGED_TIMESTAMP = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n;
60+
const JOB_ID = 'bench-job';
61+
62+
// Every scenario starts warm: index 0 is already persisted, so the scan resumes at index 1 rather than cold-starting.
63+
const PRIOR_FINALIZED_INDEX = 0;
64+
65+
// Models per-call node RPC latency so round-trip blocking time is meaningful against an otherwise-instant mock node.
66+
// The round-trip *count* is independent of this value; only `rpc-blocking-time` scales with it.
67+
const MODELED_NODE_RPC_LATENCY_MS = 5;
68+
69+
const describeBench = process.env.RUN_TAG_SYNC_BENCH ? describe : describe.skip;
70+
71+
/** One benchmark measurement in the benchmark JSON shape. */
72+
type BenchResult = { name: string; value: number; unit: string };
73+
74+
type Scenario = {
75+
label: string;
76+
kind: AppTaggingSecretKind;
77+
/** Number of secrets the recipient holds for this directional app. */
78+
secretCount: number;
79+
/** New contiguous finalized logs available per secret since the last sync (0 = steady state). */
80+
newLogs: number;
81+
/**
82+
* Optional heterogeneous load: the first `count` secrets get `newLogs` new logs each, the remaining
83+
* `secretCount - count` are idle (K = 0). When set, the scenario-level `newLogs` is ignored. Models a realistic
84+
* sync where most senders are quiet and a few are deep in catch-up.
85+
*/
86+
deepCohort?: { count: number; newLogs: number };
87+
};
88+
89+
/**
90+
* The per-secret new-log distribution for a scenario: `deepCohort.count` secrets at `deepCohort.newLogs`, the rest
91+
* idle, or a uniform `newLogs` for every secret when no cohort is set. Single source for both log seeding and the
92+
* seeding sanity check.
93+
*/
94+
function newLogsPerSecret(scenario: Scenario): number[] {
95+
return Array.from({ length: scenario.secretCount }, (_, i) =>
96+
scenario.deepCohort && i < scenario.deepCohort.count ? scenario.deepCohort.newLogs : scenario.newLogs,
97+
);
98+
}
99+
100+
const SCENARIOS: Scenario[] = [
101+
// steady-state (K = 0): no new logs since the last sync, across recipient secret counts. The dominant case and where
102+
// first-miss wins by roughly the window size.
103+
...[1, 10, 100, 1000].map(secretCount => ({
104+
label: `constrained/steady-state/secrets=${secretCount}`,
105+
kind: AppTaggingSecretKind.CONSTRAINED,
106+
secretCount,
107+
newLogs: 0,
108+
})),
109+
// Light catch-up (K new logs per secret) at 100 and 1000 secrets. Round-trips depend only on K and P, not on N, so
110+
// the two secret counts share a round-trip count and differ only in tag-queries (10x) and blocking time.
111+
...[100, 1000].flatMap(secretCount =>
112+
[1, 3].map(newLogs => ({
113+
label: `constrained/catch-up-${newLogs}/secrets=${secretCount}`,
114+
kind: AppTaggingSecretKind.CONSTRAINED,
115+
secretCount,
116+
newLogs,
117+
})),
118+
),
119+
// Deep catch-up at 100 and 1000 secrets (the negative case): round-trips grow one per probe step while tag-queries
120+
// stay at the K + 1 floor. From a full window up, the WINDOW_LEN cap forces multiple rounds at any P. As with light
121+
// catch-up, round-trips depend only on K and P (not N), so the two secret counts share a round-trip count and differ
122+
// only in tag-queries (10x) and blocking time.
123+
...[100, 1000].flatMap(secretCount =>
124+
[UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, 50, 100].map(newLogs => ({
125+
label: `constrained/catch-up-${newLogs}/secrets=${secretCount}`,
126+
kind: AppTaggingSecretKind.CONSTRAINED,
127+
secretCount,
128+
newLogs,
129+
})),
130+
),
131+
// Mixed (the realistic active sync): 999 idle senders + 1 deep straggler (K = 100). Tag-queries stay dominated by the
132+
// idle majority, but the single straggler alone sets the round-trip count (tags are batched across all secrets per
133+
// round, so the round count equals the deepest secret's), so round-trips match catch-up-100.
134+
{
135+
label: `constrained/mixed/secrets=1000`,
136+
kind: AppTaggingSecretKind.CONSTRAINED,
137+
secretCount: 1000,
138+
newLogs: 0,
139+
deepCohort: { count: 1, newLogs: 100 },
140+
},
141+
// Control: unconstrained steady state is unaffected by the optimization (windowed scan cannot first-miss).
142+
{
143+
label: `unconstrained/steady-state/secrets=100`,
144+
kind: AppTaggingSecretKind.UNCONSTRAINED,
145+
secretCount: 100,
146+
newLogs: 0,
147+
},
148+
];
149+
150+
describeBench('syncTaggedPrivateLogs constrained-sync bench', () => {
151+
const aztecNode: MockProxy<AztecNode> = mock<AztecNode>();
152+
153+
function makeFinalizedLog() {
154+
return {
155+
...randomLogResult(/* includeEffects */ true),
156+
blockNumber: FINALIZED_BLOCK_NUMBER,
157+
blockTimestamp: AGED_TIMESTAMP,
158+
};
159+
}
160+
161+
async function runScenario(scenario: Scenario) {
162+
const { kind, secretCount } = scenario;
163+
const perSecretNewLogs = newLogsPerSecret(scenario);
164+
165+
aztecNode.getPrivateLogsByTags.mockReset();
166+
const taggingStore = new RecipientTaggingStore(await openTmpStore('bench'));
167+
const secrets = await Promise.all(Array.from({ length: secretCount }, () => randomAppTaggingSecret(kind)));
168+
169+
// Seed the persisted finalized indexes to simulate a recipient that already synced prior finalized messages. The
170+
// per-secret writes are independent, so run them concurrently.
171+
await Promise.all(
172+
secrets.map(async secret => {
173+
await taggingStore.updateHighestFinalizedIndex(secret, PRIOR_FINALIZED_INDEX, JOB_ID);
174+
if (kind === AppTaggingSecretKind.UNCONSTRAINED) {
175+
await taggingStore.updateHighestAgedIndex(secret, PRIOR_FINALIZED_INDEX, JOB_ID);
176+
}
177+
}),
178+
);
179+
180+
// Tags that should resolve to a finalized log: per secret, the contiguous run
181+
// (PRIOR_FINALIZED_INDEX, PRIOR_FINALIZED_INDEX + K]. Computing the tags is independent per (secret, index).
182+
const hitTagList = await Promise.all(
183+
secrets.flatMap((secret, s) =>
184+
times(perSecretNewLogs[s], i => computeSiloedTagForIndex(secret, PRIOR_FINALIZED_INDEX + i + 1)),
185+
),
186+
);
187+
const hitTags = new Set(hitTagList.map(tag => tag.toString()));
188+
189+
aztecNode.getPrivateLogsByTags.mockImplementation(async (query: PrivateLogsQuery) => {
190+
await sleep(MODELED_NODE_RPC_LATENCY_MS);
191+
return extractTags(query).map(tag => (hitTags.has(tag.toString()) ? [makeFinalizedLog()] : []));
192+
});
193+
194+
// Wrap the node so we capture round-trips and blocking time the same way the client_flows app benches do. The
195+
// Proxy delegates to the underlying mock, so `mock.calls` still records every query for tag counting.
196+
const benchmarkedNode = BenchmarkedNodeFactory.create(aztecNode);
197+
198+
const logs = await syncTaggedPrivateLogs(
199+
secrets,
200+
benchmarkedNode,
201+
taggingStore,
202+
ANCHOR_BLOCK_HEADER,
203+
FINALIZED_BLOCK_NUMBER,
204+
JOB_ID,
205+
);
206+
207+
const calls = aztecNode.getPrivateLogsByTags.mock.calls;
208+
const tagQueries = sum(calls.map(([query]) => extractTags(query).length));
209+
210+
// Round-trips and blocking time from the same instrumentation the app benches use. `syncTaggedPrivateLogs` only
211+
// ever calls `getPrivateLogsByTags`, so every round-trip is that method.
212+
const { roundTrips } = benchmarkedNode.getStats();
213+
const rpcRoundTrips = roundTrips.roundTrips;
214+
const rpcBlockingTimeMs = roundTrips.totalBlockingTime;
215+
216+
// First-miss floor: each secret pays its K hits + 1 miss. Unconstrained cannot first-miss, so its floor is
217+
// its current cost.
218+
const firstMissOptimum =
219+
kind === AppTaggingSecretKind.CONSTRAINED ? sum(perSecretNewLogs.map(k => k + 1)) : tagQueries;
220+
221+
return {
222+
...scenario,
223+
logsFound: logs.length,
224+
tagQueries,
225+
rpcRoundTrips,
226+
rpcBlockingTimeMs,
227+
firstMissOptimum,
228+
};
229+
}
230+
231+
it('reports per-sync tag-queries, round-trips, and blocking time', async () => {
232+
const rows = [];
233+
for (const scenario of SCENARIOS) {
234+
const row = await runScenario(scenario);
235+
rows.push(row);
236+
logger.info(
237+
`${row.label.padEnd(42)} tag-queries=${String(row.tagQueries).padStart(6)} ` +
238+
`first-miss-optimum=${String(row.firstMissOptimum).padStart(6)} ` +
239+
`reduction=${(row.tagQueries / row.firstMissOptimum).toFixed(1)}x ` +
240+
`round-trips=${String(row.rpcRoundTrips).padStart(4)} ` +
241+
`blocking=${row.rpcBlockingTimeMs.toFixed(0).padStart(4)}ms logs=${String(row.logsFound).padStart(5)}`,
242+
);
243+
244+
// Seeding sanity check only: every seeded log must be found, or the reported numbers measure a broken harness.
245+
// Scan behavior (probe schedules, round counts) is pinned by the unit tests, which run in CI while this does not.
246+
expect(row.logsFound).toBe(sum(newLogsPerSecret(scenario)));
247+
248+
// Steady state is one round trip by construction: every secret first-misses in round one, independent of secret
249+
// count, so a wide round's chunked parallel RPC calls must count as a single blocking wait. Guards the round-trip
250+
// accounting at widths the unit tests don't reach (they count RPC calls, not round trips).
251+
if (scenario.newLogs === 0 && !scenario.deepCohort) {
252+
expect(row.rpcRoundTrips).toBe(1);
253+
}
254+
}
255+
256+
const results: BenchResult[] = rows.flatMap(row => [
257+
{ name: `TagSync/${row.label}/tag-queries`, value: row.tagQueries, unit: 'tag-queries' },
258+
{ name: `TagSync/${row.label}/rpc-round-trips`, value: row.rpcRoundTrips, unit: 'round_trips' },
259+
{ name: `TagSync/${row.label}/rpc-blocking-time`, value: Number(row.rpcBlockingTimeMs.toFixed(2)), unit: 'ms' },
260+
]);
261+
262+
if (process.env.BENCH_OUTPUT) {
263+
await mkdir(path.dirname(process.env.BENCH_OUTPUT), { recursive: true });
264+
await writeFile(process.env.BENCH_OUTPUT, JSON.stringify(results, null, 2));
265+
}
266+
}, 600_000);
267+
});

0 commit comments

Comments
 (0)