diff --git a/yarn-project/pxe/src/tagging/constants.ts b/yarn-project/pxe/src/tagging/constants.ts index 4bf0cd1878d4..b2d7fd0173f2 100644 --- a/yarn-project/pxe/src/tagging/constants.ts +++ b/yarn-project/pxe/src/tagging/constants.ts @@ -18,3 +18,11 @@ import { MAX_PRIVATE_LOGS_PER_TX } from '@aztec/constants'; // reserved at log emission time, before squashing is decided, and the kernel's reset/squash loop is not bounded by // MAX_PRIVATE_LOGS_PER_TX. No fixed window value closes that gap. export const UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN = MAX_PRIVATE_LOGS_PER_TX + 20; + +// The number of tags probed per constrained secret in the first round. The probe then doubles each round (1, 2, 4, ..., +// capped at UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN) while every probed index is a hit, stopping at the first missing tag. +// Constrained delivery is gapless, so a single missing tag proves the stream has ended: at steady state this turns a full +// WINDOW_LEN probe into a single tag. A secret K logs behind catches up in ~log2(K) round-trips while the probe is still +// doubling (1, 2, 4, 8, 16), but once it saturates the cap and advances WINDOW_LEN tags per round, deeper catch-up is +// linear at ~K/WINDOW_LEN rounds. Either way it beats both the full window every round and one round per log. +export const INITIAL_CONSTRAINED_PROBE_LEN = 1; diff --git a/yarn-project/pxe/src/tagging/index.ts b/yarn-project/pxe/src/tagging/index.ts index e4f7765c35a2..462d0bdaec4b 100644 --- a/yarn-project/pxe/src/tagging/index.ts +++ b/yarn-project/pxe/src/tagging/index.ts @@ -12,7 +12,7 @@ export { syncTaggedPrivateLogs } from './recipient_sync/sync_tagged_private_logs.js'; export { syncSenderTaggingIndexes } from './sender_sync/sync_sender_tagging_indexes.js'; export { persistSenderTaggingIndexRangesForTx } from './persist_sender_tagging_index_ranges.js'; -export { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN } from './constants.js'; +export { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, INITIAL_CONSTRAINED_PROBE_LEN } from './constants.js'; export { getAllPrivateLogsByTags, getAllPublicLogsByTagsFromContract } from './get_all_logs_by_tags.js'; // Re-export tagging-related types from stdlib diff --git a/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.bench.test.ts b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.bench.test.ts new file mode 100644 index 000000000000..69b43797c1b6 --- /dev/null +++ b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.bench.test.ts @@ -0,0 +1,279 @@ +import { MAX_TX_LIFETIME } from '@aztec/constants'; +import { BlockNumber } from '@aztec/foundation/branded-types'; +import { createLogger } from '@aztec/foundation/log'; +import { sleep } from '@aztec/foundation/sleep'; +import { openTmpStore } from '@aztec/kv-store/lmdb-v2'; +import type { AztecNode } from '@aztec/stdlib/interfaces/server'; +import { + type AppTaggingSecret, + AppTaggingSecretKind, + type PrivateLogsQuery, + SiloedTag, + type TagQuery, + randomLogResult, +} from '@aztec/stdlib/logs'; +import { randomAppTaggingSecret } from '@aztec/stdlib/testing'; +import { BlockHeader } from '@aztec/stdlib/tx'; + +import { mkdir, writeFile } from 'fs/promises'; +import { type MockProxy, mock } from 'jest-mock-extended'; +import path from 'path'; + +import { BenchmarkedNodeFactory } from '../../contract_function_simulator/benchmarked_node.js'; +import { RecipientTaggingStore } from '../../storage/tagging_store/recipient_tagging_store.js'; +import { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, syncTaggedPrivateLogs } from '../index.js'; + +/** + * Benchmark for constrained recipient tag-sync. + * + * Measures the per-sync cost of `syncTaggedPrivateLogs` for constrained secrets. Constrained streams are gapless, so + * the scan probes a small initial window (`INITIAL_CONSTRAINED_PROBE_LEN`) and doubles it each round (capped at the + * `UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN` window), stopping at the first missing tag instead of fetching the + * full window. This only reports costs; the scan behavior itself (probe schedules, round counts) is pinned by the + * unit tests in `sync_tagged_private_logs.test.ts`, which run in CI while this bench is opt-in. + * + * Manual run: + * ```bash + * RUN_TAG_SYNC_BENCH=1 JEST_MAX_WORKERS=1 BENCH_OUTPUT=/tmp/tag-sync-bench-current.json \ + * yarn workspace @aztec/pxe test src/tagging/recipient_sync/sync_tagged_private_logs.bench.test.ts + * ``` + * + * Metrics, per scenario: + * - `tag-queries`: total tags queried, the throughput win. + * - `rpc-round-trips`: sequential blocking waits on the node, via `BenchmarkedNodeFactory`. + * The latency axis: doubling grows the probe geometrically, so round-trips rise only ~log2(K) while the + * probe is still doubling, then linearly at ~K/WINDOW_LEN once it saturates the cap. + * Depends only on K, not on secret count. A round's tags are chunked at MAX_RPC_LEN (=100) into parallel calls + * internally, but those overlap, so a wide round is still one round-trip; that is why + * round-trips, not raw call count, is the latency axis. + * - `rpc-blocking-time`: measured wall-clock the caller blocks on the node, under a modeled + * `MODELED_NODE_RPC_LATENCY_MS` per call plus a little per-round overhead. Parallel calls within a round overlap, so + * it tracks round-trips (a 1000-secret round is many parallel chunks but ~one round-trip of blocking time). + * + * Scenario labels: `steady-state` is no new logs (K = 0); `catch-up-K` is K new contiguous logs per secret since the + * last sync; `secrets=N` is N secrets synced together in one batched pass. Because round-trips depend only on K (not + * N), the light catch-up scenarios run at both 100 and 1000 secrets to show tag-queries scale with N while round-trips + * do not. The `mixed` row is the realistic active sync (999 idle secrets + 1 deep straggler at K = 100): it isolates + * that tag-queries stay dominated by the idle majority while a single straggler alone sets the round-trip count. + */ + +const logger = createLogger('pxe:tagging:bench'); + +const FINALIZED_BLOCK_NUMBER = BlockNumber(10); +const ANCHOR_BLOCK_NUMBER = BlockNumber(100); +const CURRENT_TIMESTAMP = BigInt(Math.floor(Date.now() / 1000)); +const ANCHOR_BLOCK_HEADER = BlockHeader.random({ blockNumber: ANCHOR_BLOCK_NUMBER, timestamp: CURRENT_TIMESTAMP }); +const AGED_TIMESTAMP = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; +const JOB_ID = 'bench-job'; + +// Every scenario starts warm: index 0 is already persisted, so the scan resumes at index 1 rather than cold-starting. +const PRIOR_FINALIZED_INDEX = 0; + +// Models per-call node RPC latency so round-trip blocking time is meaningful against an otherwise-instant mock node. +// The round-trip *count* is independent of this value; only `rpc-blocking-time` scales with it. +const MODELED_NODE_RPC_LATENCY_MS = 5; + +const describeBench = process.env.RUN_TAG_SYNC_BENCH ? describe : describe.skip; + +/** One benchmark measurement in the benchmark JSON shape. */ +type BenchResult = { name: string; value: number; unit: string }; + +type Scenario = { + label: string; + kind: AppTaggingSecretKind; + /** Number of secrets the recipient holds for this directional app. */ + secretCount: number; + /** New contiguous finalized logs available per secret since the last sync (0 = steady state). */ + newLogs: number; + /** + * Optional heterogeneous load: the first `count` secrets get `newLogs` new logs each, the remaining + * `secretCount - count` are idle (K = 0). When set, the scenario-level `newLogs` is ignored. Models a realistic + * sync where most senders are quiet and a few are deep in catch-up. + */ + deepCohort?: { count: number; newLogs: number }; +}; + +/** + * The per-secret new-log distribution for a scenario: `deepCohort.count` secrets at `deepCohort.newLogs`, the rest + * idle, or a uniform `newLogs` for every secret when no cohort is set. Single source for both log seeding and the + * seeding sanity check. + */ +function newLogsPerSecret(scenario: Scenario): number[] { + return Array.from({ length: scenario.secretCount }, (_, i) => + scenario.deepCohort && i < scenario.deepCohort.count ? scenario.deepCohort.newLogs : scenario.newLogs, + ); +} + +const SCENARIOS: Scenario[] = [ + // steady-state (K = 0): no new logs since the last sync, across recipient secret counts. The dominant case and where + // first-miss wins by roughly the window size. + ...[1, 10, 100, 1000].map(secretCount => ({ + label: `constrained/steady-state/secrets=${secretCount}`, + kind: AppTaggingSecretKind.CONSTRAINED, + secretCount, + newLogs: 0, + })), + // 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 + // the two secret counts share a round-trip count and differ only in tag-queries (10x) and blocking time. + ...[100, 1000].flatMap(secretCount => + [1, 3].map(newLogs => ({ + label: `constrained/catch-up-${newLogs}/secrets=${secretCount}`, + kind: AppTaggingSecretKind.CONSTRAINED, + secretCount, + newLogs, + })), + ), + // Deep catch-up at 100 and 1000 secrets (the negative case): round-trips grow one per probe step while tag-queries + // stay at the K + 1 floor. From a full window up, the WINDOW_LEN cap forces multiple rounds at any P. As with light + // catch-up, round-trips depend only on K and P (not N), so the two secret counts share a round-trip count and differ + // only in tag-queries (10x) and blocking time. + ...[100, 1000].flatMap(secretCount => + [UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, 50, 100].map(newLogs => ({ + label: `constrained/catch-up-${newLogs}/secrets=${secretCount}`, + kind: AppTaggingSecretKind.CONSTRAINED, + secretCount, + newLogs, + })), + ), + // Mixed (the realistic active sync): 999 idle senders + 1 deep straggler (K = 100). Tag-queries stay dominated by the + // idle majority, but the single straggler alone sets the round-trip count (tags are batched across all secrets per + // round, so the round count equals the deepest secret's), so round-trips match catch-up-100. + { + label: `constrained/mixed/secrets=1000`, + kind: AppTaggingSecretKind.CONSTRAINED, + secretCount: 1000, + newLogs: 0, + deepCohort: { count: 1, newLogs: 100 }, + }, + // Control: unconstrained steady state is unaffected by the optimization (windowed scan cannot first-miss). + { + label: `unconstrained/steady-state/secrets=100`, + kind: AppTaggingSecretKind.UNCONSTRAINED, + secretCount: 100, + newLogs: 0, + }, +]; + +describeBench('syncTaggedPrivateLogs constrained-sync bench', () => { + const aztecNode: MockProxy = mock(); + + function computeSiloedTagForIndex(secret: AppTaggingSecret, index: number) { + return SiloedTag.compute({ extendedSecret: secret, index }); + } + + function extractTags(query: PrivateLogsQuery): SiloedTag[] { + return query.tags.map((entry: TagQuery) => (entry instanceof SiloedTag ? entry : entry.tag)); + } + + function makeFinalizedLog() { + return { + ...randomLogResult(/* includeEffects */ true), + blockNumber: FINALIZED_BLOCK_NUMBER, + blockTimestamp: AGED_TIMESTAMP, + }; + } + + async function runScenario(scenario: Scenario) { + const { kind, secretCount } = scenario; + const perSecretNewLogs = newLogsPerSecret(scenario); + + aztecNode.getPrivateLogsByTags.mockReset(); + const taggingStore = new RecipientTaggingStore(await openTmpStore('bench')); + const secrets = await Promise.all(Array.from({ length: secretCount }, () => randomAppTaggingSecret(kind))); + + // Seed the persisted finalized indexes to simulate a recipient that already synced prior finalized messages. + for (const secret of secrets) { + await taggingStore.updateHighestFinalizedIndex(secret, PRIOR_FINALIZED_INDEX, JOB_ID); + if (kind === AppTaggingSecretKind.UNCONSTRAINED) { + await taggingStore.updateHighestAgedIndex(secret, PRIOR_FINALIZED_INDEX, JOB_ID); + } + } + + // Tags that should resolve to a finalized log: per secret, the contiguous run + // (PRIOR_FINALIZED_INDEX, PRIOR_FINALIZED_INDEX + K]. + const hitTags = new Set(); + for (let s = 0; s < secrets.length; s++) { + for (let k = 1; k <= perSecretNewLogs[s]; k++) { + hitTags.add((await computeSiloedTagForIndex(secrets[s], PRIOR_FINALIZED_INDEX + k)).toString()); + } + } + + aztecNode.getPrivateLogsByTags.mockImplementation(async (query: PrivateLogsQuery) => { + await sleep(MODELED_NODE_RPC_LATENCY_MS); + return extractTags(query).map(tag => (hitTags.has(tag.toString()) ? [makeFinalizedLog()] : [])); + }); + + // Wrap the node so we capture round-trips and blocking time the same way the client_flows app benches do. The + // Proxy delegates to the underlying mock, so `mock.calls` still records every query for tag counting. + const benchmarkedNode = BenchmarkedNodeFactory.create(aztecNode); + + const logs = await syncTaggedPrivateLogs( + secrets, + benchmarkedNode, + taggingStore, + ANCHOR_BLOCK_HEADER, + FINALIZED_BLOCK_NUMBER, + JOB_ID, + ); + + const calls = aztecNode.getPrivateLogsByTags.mock.calls; + const tagQueries = calls.reduce((sum, [query]) => sum + extractTags(query).length, 0); + + // Round-trips and blocking time from the same instrumentation the app benches use. `syncTaggedPrivateLogs` only + // ever calls `getPrivateLogsByTags`, so every round-trip is that method. + const { roundTrips } = benchmarkedNode.getStats(); + const rpcRoundTrips = roundTrips.roundTrips; + const rpcBlockingTimeMs = roundTrips.totalBlockingTime; + + // First-miss floor: each secret pays its K hits + 1 miss. Unconstrained cannot first-miss, so its floor is + // its current cost. + const firstMissOptimum = + kind === AppTaggingSecretKind.CONSTRAINED ? perSecretNewLogs.reduce((sum, k) => sum + k + 1, 0) : tagQueries; + + return { + ...scenario, + logsFound: logs.length, + tagQueries, + rpcRoundTrips, + rpcBlockingTimeMs, + firstMissOptimum, + }; + } + + it('reports per-sync tag-queries, round-trips, and blocking time', async () => { + const rows = []; + for (const scenario of SCENARIOS) { + const row = await runScenario(scenario); + rows.push(row); + logger.info( + `${row.label.padEnd(42)} tag-queries=${String(row.tagQueries).padStart(6)} ` + + `first-miss-optimum=${String(row.firstMissOptimum).padStart(6)} ` + + `reduction=${(row.tagQueries / row.firstMissOptimum).toFixed(1)}x ` + + `round-trips=${String(row.rpcRoundTrips).padStart(4)} ` + + `blocking=${row.rpcBlockingTimeMs.toFixed(0).padStart(4)}ms logs=${String(row.logsFound).padStart(5)}`, + ); + + // Seeding sanity check only: every seeded log must be found, or the reported numbers measure a broken harness. + // Scan behavior (probe schedules, round counts) is pinned by the unit tests, which run in CI while this does not. + expect(row.logsFound).toBe(newLogsPerSecret(scenario).reduce((sum, k) => sum + k, 0)); + + // Steady state is one round trip by construction: every secret first-misses in round one, independent of secret + // count, so a wide round's chunked parallel RPC calls must count as a single blocking wait. Guards the round-trip + // accounting at widths the unit tests don't reach (they count RPC calls, not round trips). + if (scenario.newLogs === 0 && !scenario.deepCohort) { + expect(row.rpcRoundTrips).toBe(1); + } + } + + const results: BenchResult[] = rows.flatMap(row => [ + { name: `TagSync/${row.label}/tag-queries`, value: row.tagQueries, unit: 'tag-queries' }, + { name: `TagSync/${row.label}/rpc-round-trips`, value: row.rpcRoundTrips, unit: 'round_trips' }, + { name: `TagSync/${row.label}/rpc-blocking-time`, value: Number(row.rpcBlockingTimeMs.toFixed(2)), unit: 'ms' }, + ]); + + if (process.env.BENCH_OUTPUT) { + await mkdir(path.dirname(process.env.BENCH_OUTPUT), { recursive: true }); + await writeFile(process.env.BENCH_OUTPUT, JSON.stringify(results, null, 2)); + } + }, 600_000); +}); diff --git a/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.test.ts b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.test.ts index de30653595a8..e5ae328df61c 100644 --- a/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.test.ts +++ b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.test.ts @@ -1,6 +1,6 @@ import { MAX_TX_LIFETIME } from '@aztec/constants'; import { BlockNumber } from '@aztec/foundation/branded-types'; -import type { Fr } from '@aztec/foundation/curves/bn254'; +import { times, timesParallel } from '@aztec/foundation/collection'; import { openTmpStore } from '@aztec/kv-store/lmdb-v2'; import { MAX_RPC_LEN } from '@aztec/stdlib/interfaces/api-limit'; import type { AztecNode } from '@aztec/stdlib/interfaces/server'; @@ -18,12 +18,21 @@ import { BlockHeader } from '@aztec/stdlib/tx'; import { type MockProxy, mock } from 'jest-mock-extended'; import { RecipientTaggingStore } from '../../storage/tagging_store/recipient_tagging_store.js'; -import { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, syncTaggedPrivateLogs } from '../index.js'; +import { + INITIAL_CONSTRAINED_PROBE_LEN, + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, + syncTaggedPrivateLogs, +} from '../index.js'; const FAR_FUTURE_BLOCK_NUMBER = BlockNumber(100); const CURRENT_TIMESTAMP = BigInt(Math.floor(Date.now() / 1000)); const ANCHOR_BLOCK_HEADER = BlockHeader.random({ blockNumber: FAR_FUTURE_BLOCK_NUMBER, timestamp: CURRENT_TIMESTAMP }); const JOB_ID = 'test-job'; +const FINALIZED_BLOCK_NUMBER = BlockNumber(10); +// Old enough that the log is past MAX_TX_LIFETIME and may advance the aged index. +const AGED_TIMESTAMP = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; +// Recent enough that the log could still belong to a pending tx and must not advance the aged index. +const RECENT_TIMESTAMP = CURRENT_TIMESTAMP - 5000n; describe('syncTaggedPrivateLogs', () => { const aztecNode: MockProxy = mock(); @@ -33,7 +42,19 @@ describe('syncTaggedPrivateLogs', () => { return SiloedTag.compute({ extendedSecret: secret, index }); } - function makeLog(blockNumber: number, blockTimestamp: bigint, _tag: Fr) { + function computeSiloedTags(secret: AppTaggingSecret, indexes: number[]): Promise { + return Promise.all(indexes.map(i => computeSiloedTagForIndex(secret, i))); + } + + /** Computes the tags of `count` contiguous indexes starting at `firstIndex`. */ + function computeSiloedTagRange(secret: AppTaggingSecret, count: number, firstIndex = 0): Promise { + return computeSiloedTags( + secret, + times(count, i => firstIndex + i), + ); + } + + function makeLog(blockNumber: number, blockTimestamp: bigint) { return { ...randomLogResult(/* includeEffects */ true), blockNumber: BlockNumber(blockNumber), blockTimestamp }; } @@ -44,25 +65,98 @@ describe('syncTaggedPrivateLogs', () => { return query.tags.map((entry: TagQuery) => (entry instanceof SiloedTag ? entry : entry.tag)); } - function mockNodeWithLogs(logTags: SiloedTag[], blockNumber: number, blockTimestamp: bigint) { + /** Mocks the node to return one log per matching tag per group, at the group's block number and timestamp. */ + function mockNodeWithLogGroups(groups: { tags: SiloedTag[]; blockNumber?: number; blockTimestamp?: bigint }[]) { aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { const tags = extractTags(query); return Promise.resolve( - tags.map((t: SiloedTag) => { - const match = logTags.find(tag => tag.equals(t)); - return match ? [makeLog(blockNumber, blockTimestamp, match.value)] : []; - }), + tags.map((t: SiloedTag) => + groups.flatMap(group => + group.tags + .filter(tag => tag.equals(t)) + .map(() => + makeLog(group.blockNumber ?? Number(FINALIZED_BLOCK_NUMBER), group.blockTimestamp ?? AGED_TIMESTAMP), + ), + ), + ), ); }); } + /** Mocks the node to return one aged, finalized log per matching tag; repeat a tag to return multiple logs for it. */ + function mockNodeWithLogs(logTags: SiloedTag[], blockNumber?: number, blockTimestamp?: bigint) { + mockNodeWithLogGroups([{ tags: logTags, blockNumber, blockTimestamp }]); + } + + /** Runs syncTaggedPrivateLogs against the mocked node and the store under test. */ + function sync( + secrets: AppTaggingSecret[], + finalizedBlockNumber = FINALIZED_BLOCK_NUMBER, + header = ANCHOR_BLOCK_HEADER, + ) { + return syncTaggedPrivateLogs(secrets, aztecNode, taggingStore, header, finalizedBlockNumber, JOB_ID); + } + + /** The tags queried by the `callIndex`-th RPC call. */ + function calledTags(callIndex = 0): SiloedTag[] { + return extractTags(aztecNode.getPrivateLogsByTags.mock.calls[callIndex][0]); + } + + /** The number of tags queried by each RPC call, in call order. */ + function callSizes(): number[] { + return aztecNode.getPrivateLogsByTags.mock.calls.map(([query]) => extractTags(query).length); + } + + /** Every tag queried across all RPC calls, in call order. */ + function allCalledTags(): SiloedTag[] { + return aztecNode.getPrivateLogsByTags.mock.calls.flatMap(([query]) => extractTags(query)); + } + + /** + * Models the constrained probe schedule for draining `logCount` contiguous finalized logs starting at + * `firstLogIndex`: the half-open [start, end) tag-index range each sync round is expected to query. + * + * E.g. 3 logs at indexes 1..3 give [1, 2), [2, 4), [4, 8): the probe doubles after each fully-hit round and the + * miss at index 4 ends the scan. + */ + function expectedConstrainedProbeRanges(logCount: number, firstLogIndex = 1): { start: number; end: number }[] { + const ranges: { start: number; end: number }[] = []; + const lastLogIndex = firstLogIndex + logCount - 1; + let start = firstLogIndex; + let highestFinalizedIndex = firstLogIndex - 1; + // Exclusive end of the probing window, re-anchored past the highest finalized index as hits land. + let boundEnd = highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1; + let probeLen = INITIAL_CONSTRAINED_PROBE_LEN; + + for (;;) { + const end = Math.min(boundEnd, start + probeLen); + ranges.push({ start, end }); + + const highestHitInRange = Math.min(end - 1, lastLogIndex); + const probeFullyConsumed = highestHitInRange === end - 1; + if (highestHitInRange >= start) { + highestFinalizedIndex = highestHitInRange; + boundEnd = Math.max(boundEnd, highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1); + } + + // A miss inside the probe means the gapless stream ended; hitting the window bound also stops the scan. + if (!probeFullyConsumed || end >= boundEnd) { + return ranges; + } + + // The probe doubles after every fully-hit round, capped at the window length. + start = end; + probeLen = Math.min(probeLen * 2, UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN); + } + } + beforeEach(async () => { aztecNode.getPrivateLogsByTags.mockReset(); taggingStore = new RecipientTaggingStore(await openTmpStore('test')); }); it('returns empty array when given no secrets', async () => { - const logs = await syncTaggedPrivateLogs([], aztecNode, taggingStore, ANCHOR_BLOCK_HEADER, BlockNumber(10), JOB_ID); + const logs = await sync([]); expect(logs).toHaveLength(0); expect(aztecNode.getPrivateLogsByTags).not.toHaveBeenCalled(); @@ -70,49 +164,31 @@ describe('syncTaggedPrivateLogs', () => { it('returns empty array when no logs found for any secret', async () => { const secrets = await makeSecrets(3, AppTaggingSecretKind.UNCONSTRAINED); - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { - const tags = extractTags(query); - return Promise.resolve(tags.map(() => [])); - }); + mockNodeWithLogs([]); - const logs = await syncTaggedPrivateLogs( - secrets, - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - BlockNumber(10), - JOB_ID, - ); + const logs = await sync(secrets); expect(logs).toHaveLength(0); }); - it('batches tags from multiple secrets across as few RPC calls as MAX_RPC_LEN allows', async () => { + it('batches tags from multiple secrets across as few RPC calls as the RPC limit allows', async () => { // Pick enough secrets that the total tag count spans several MAX_RPC_LEN chunks. A per-secret // implementation would need one RPC per secret; batched behavior needs ceil(totalTags / MAX_RPC_LEN). const numSecrets = 10; const secrets = await makeSecrets(numSecrets, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); + mockNodeWithLogs([]); - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { - const tags = extractTags(query); - return Promise.resolve(tags.map(() => [])); - }); - - await syncTaggedPrivateLogs(secrets, aztecNode, taggingStore, ANCHOR_BLOCK_HEADER, finalizedBlockNumber, JOB_ID); + await sync(secrets); - const expectedTags = await Promise.all( - secrets.flatMap(secret => - Array.from({ length: UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1 }, (_, i) => - computeSiloedTagForIndex(secret, i), - ), - ), - ); - const calledTags = aztecNode.getPrivateLogsByTags.mock.calls.flatMap(([query]) => extractTags(query)); + const expectedTags = ( + await Promise.all( + secrets.map(secret => computeSiloedTagRange(secret, UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1)), + ) + ).flat(); const asStrings = (tags: SiloedTag[]) => tags.map(t => t.toString()).sort(); // Every expected (secret, index) tag was queried exactly once, in some order across the batched RPC calls. - expect(asStrings(calledTags)).toEqual(asStrings(expectedTags)); + expect(asStrings(allCalledTags())).toEqual(asStrings(expectedTags)); // Batching invariant: the sync issues ceil(totalTags / MAX_RPC_LEN) calls, which is strictly fewer than one // RPC per secret. This is what a per-secret implementation would degenerate to. @@ -123,24 +199,15 @@ describe('syncTaggedPrivateLogs', () => { it('syncs logs and updates store independently per secret', async () => { const secrets = await makeSecrets(3, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; const log1Index = 3; const log2Index = 7; - const log1Tag = await computeSiloedTagForIndex(secrets[0], log1Index); - const log2Tag = await computeSiloedTagForIndex(secrets[1], log2Index); - - mockNodeWithLogs([log1Tag, log2Tag], Number(finalizedBlockNumber), logBlockTimestamp); - - const logs = await syncTaggedPrivateLogs( - secrets, - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + mockNodeWithLogs([ + await computeSiloedTagForIndex(secrets[0], log1Index), + await computeSiloedTagForIndex(secrets[1], log2Index), + ]); + + const logs = await sync(secrets); expect(logs).toHaveLength(2); expect(await taggingStore.getHighestAgedIndex(secrets[0], JOB_ID)).toBe(log1Index); @@ -153,45 +220,34 @@ describe('syncTaggedPrivateLogs', () => { }); it('does not advance aged index for recent logs', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - 5000n; // not aged + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); const logIndex = 5; - const logTag = await computeSiloedTagForIndex(secret, logIndex); - - mockNodeWithLogs([logTag], Number(finalizedBlockNumber), logBlockTimestamp); + mockNodeWithLogs( + [await computeSiloedTagForIndex(secret, logIndex)], + Number(FINALIZED_BLOCK_NUMBER), + RECENT_TIMESTAMP, + ); - await syncTaggedPrivateLogs([secret], aztecNode, taggingStore, ANCHOR_BLOCK_HEADER, finalizedBlockNumber, JOB_ID); + const logs = await sync([secret]); + // The recent log is still returned to the caller: recency only gates the aged index, not delivery. + expect(logs).toHaveLength(1); expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(logIndex); expect(await taggingStore.getHighestAgedIndex(secret, JOB_ID)).toBeUndefined(); }); it('updates store correctly when multiple iterations are needed', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const agedBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); // A log at the last index of the initial window [0, WINDOW_LEN] moves the finalized index to WINDOW_LEN, - // which shifts the next window forward and triggers a second iteration. + // which shifts the next window forward and triggers a second iteration. A second log sits in the advanced + // window, only reachable in the second iteration. const lastIndexInInitialWindow = UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN; - const log1Tag = await computeSiloedTagForIndex(secret, lastIndexInInitialWindow); - - // A second log sits in the advanced window, only reachable in the second iteration. const newWindowIndex = lastIndexInInitialWindow + 3; - const log2Tag = await computeSiloedTagForIndex(secret, newWindowIndex); + mockNodeWithLogs(await computeSiloedTags(secret, [lastIndexInInitialWindow, newWindowIndex])); - mockNodeWithLogs([log1Tag, log2Tag], Number(finalizedBlockNumber), agedBlockTimestamp); - - const logs = await syncTaggedPrivateLogs( - [secret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + const logs = await sync([secret]); expect(logs).toHaveLength(2); expect(await taggingStore.getHighestAgedIndex(secret, JOB_ID)).toBe(newWindowIndex); @@ -199,229 +255,346 @@ describe('syncTaggedPrivateLogs', () => { }); it('respects pre-existing store indexes', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); const existingAgedIndex = 5; const existingFinalizedIndex = 8; await taggingStore.updateHighestAgedIndex(secret, existingAgedIndex, JOB_ID); await taggingStore.updateHighestFinalizedIndex(secret, existingFinalizedIndex, JOB_ID); + mockNodeWithLogs([]); - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => - Promise.resolve(query.tags.map(() => [])), - ); - - await syncTaggedPrivateLogs([secret], aztecNode, taggingStore, ANCHOR_BLOCK_HEADER, finalizedBlockNumber, JOB_ID); - - const calledTags = extractTags(aztecNode.getPrivateLogsByTags.mock.calls[0][0]); + await sync([secret]); // The query window must start at existingAgedIndex+1 and end at existingFinalizedIndex+WINDOW_LEN (inclusive). const expectedStart = existingAgedIndex + 1; const expectedEnd = existingFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN; - const expectedTags = await Promise.all( - Array.from({ length: expectedEnd - expectedStart + 1 }, (_, i) => - computeSiloedTagForIndex(secret, expectedStart + i), - ), - ); - - expect(calledTags).toEqual(expectedTags); + expect(calledTags()).toEqual(await computeSiloedTagRange(secret, expectedEnd - expectedStart + 1, expectedStart)); }); it('handles multiple logs at the same tag index', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); - const logIndex = 3; - const logTag = await computeSiloedTagForIndex(secret, logIndex); + // The tag appears twice, so the node returns two logs for it. + const logTag = await computeSiloedTagForIndex(secret, 3); + mockNodeWithLogs([logTag, logTag]); - // Two logs returned for the same tag - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { - const tags = extractTags(query); - return Promise.resolve( - tags.map((t: SiloedTag) => - t.equals(logTag) - ? [ - makeLog(Number(finalizedBlockNumber), logBlockTimestamp, logTag.value), - makeLog(Number(finalizedBlockNumber), logBlockTimestamp, logTag.value), - ] - : [], - ), - ); - }); - - const logs = await syncTaggedPrivateLogs( - [secret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + const logs = await sync([secret]); expect(logs).toHaveLength(2); }); describe('constrained secrets', () => { it('stops at first gap and does not track aged index', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.CONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; - - const logTags = await Promise.all([0, 1, 2].map(i => computeSiloedTagForIndex(secret, i))); - mockNodeWithLogs(logTags, Number(finalizedBlockNumber), logBlockTimestamp); - - const logs = await syncTaggedPrivateLogs( - [secret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + mockNodeWithLogs(await computeSiloedTags(secret, [0, 1, 2])); + + const logs = await sync([secret]); expect(logs).toHaveLength(3); expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(2); expect(await taggingStore.getHighestAgedIndex(secret, JOB_ID)).toBeUndefined(); }); - it('continues when all indexes in the batch have logs', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.CONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; - - const totalLogs = UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 2; - const logTags = await Promise.all( - Array.from({ length: totalLogs }, (_, i) => computeSiloedTagForIndex(secret, i)), - ); + it('advances the finalized index only through the finalized prefix', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + const finalizedBlockNumber = BlockNumber(5); - mockNodeWithLogs(logTags, Number(finalizedBlockNumber), logBlockTimestamp); + // Indexes 0..3 are finalized; indexes 4 and 5 are hits in a block past the finalized one. + mockNodeWithLogGroups([ + { tags: await computeSiloedTags(secret, [0, 1, 2, 3]), blockNumber: Number(finalizedBlockNumber) }, + { tags: await computeSiloedTags(secret, [4, 5]), blockNumber: 8, blockTimestamp: RECENT_TIMESTAMP }, + ]); - const logs = await syncTaggedPrivateLogs( - [secret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + const logs = await sync([secret], finalizedBlockNumber); - expect(logs).toHaveLength(totalLogs); - expect(aztecNode.getPrivateLogsByTags).toHaveBeenCalledTimes(2); + // The unfinalized logs (4, 5) are returned to the caller, but the finalized index only advances to the finalized + // prefix (3): probe advancement is decoupled from the finalized index. + expect(logs).toHaveLength(6); + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(3); }); - it('persists cursor only up to finalized block', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.CONSTRAINED); + it('advances the probe past an unfinalized-only first probe', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); const finalizedBlockNumber = BlockNumber(5); - const oldTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; - const recentTimestamp = CURRENT_TIMESTAMP - 5000n; - - const finalizedTags = await Promise.all([0, 1, 2, 3].map(i => computeSiloedTagForIndex(secret, i))); - const unfinalizedTags = await Promise.all([4, 5].map(i => computeSiloedTagForIndex(secret, i))); - - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { - const tags = extractTags(query); - return Promise.resolve( - tags.map((t: SiloedTag) => { - if (finalizedTags.find(tag => tag.equals(t))) { - return [makeLog(Number(finalizedBlockNumber), oldTimestamp, t.value)]; - } - if (unfinalizedTags.find(tag => tag.equals(t))) { - return [makeLog(8, recentTimestamp, t.value)]; - } - return []; - }), - ); - }); - - const logs = await syncTaggedPrivateLogs( - [secret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); - expect(logs).toHaveLength(6); + // Indexes 0 and 1 are hits in an unfinalized block (8 > finalized 5); index 2 is the gap. With the small initial + // probe, index 0 is probed alone and is unfinalized, so the scan must still advance to discover index 1 — gating + // advancement on finalization would drop it. + mockNodeWithLogs(await computeSiloedTags(secret, [0, 1]), 8, RECENT_TIMESTAMP); + + const logs = await sync([secret], finalizedBlockNumber); + + expect(logs).toHaveLength(2); + // Nothing finalized, so the finalized index must not advance. + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBeUndefined(); + + // Round 1 probes [0] and advances on the unfinalized hit; round 2 probes [1, 2] and stops at the gap (2). + expect(callSizes()).toEqual([1, 2]); + + // The store only ever advances through finalized logs, so an unfinalized log can never be skipped: since nothing + // was persisted, a second sync restarts at index 0 and re-fetches both unfinalized logs. + aztecNode.getPrivateLogsByTags.mockClear(); + const secondSyncLogs = await sync([secret], finalizedBlockNumber); + expect(secondSyncLogs).toHaveLength(2); + expect(calledTags()).toEqual(await computeSiloedTags(secret, [0])); + // The repeat sync saw the same unfinalized-only hits, so the finalized index must still not advance. + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBeUndefined(); + }); + + // Pins the probe schedule: the probe doubles each round (1, 2, 4, ...) until the first miss, so K-deep + // catch-up resolves in ~log2(K) round-trips instead of K + 1. With 3 new logs the windows are [1], [2,3], + // [4,5,6,7] - round 3 (probe length 4) contains the terminating miss at index 4. + it('doubling catch-up grows the probe geometrically and stops at the first miss', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // Recipient already synced index 0; three new finalized logs sit at indexes 1..3. + await taggingStore.updateHighestFinalizedIndex(secret, 0, JOB_ID); + mockNodeWithLogs(await computeSiloedTagRange(secret, 3, 1)); + + const logs = await sync([secret]); + + expect(logs).toHaveLength(3); expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(3); + + // Probe windows double each round: [1], then [2,3], then [4,5,6,7] where index 4 is the terminating miss. + expect(aztecNode.getPrivateLogsByTags).toHaveBeenCalledTimes(3); + expect(calledTags(0)).toEqual(await computeSiloedTags(secret, [1])); + expect(calledTags(1)).toEqual(await computeSiloedTags(secret, [2, 3])); + expect(calledTags(2)).toEqual(await computeSiloedTags(secret, [4, 5, 6, 7])); + }); + + // Pins the effective per-round query cap and that deep catch-up is linear past the cap, not logarithmic: the probe + // doubles until it saturates at WINDOW_LEN per round rather than growing without bound. + it('caps the doubling probe at the window length so deep catch-up advances linearly', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // Recipient already synced index 0; a deep run of finalized logs sits past multiple capped probe windows. + const newLogs = UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN * 3; + await taggingStore.updateHighestFinalizedIndex(secret, 0, JOB_ID); + mockNodeWithLogs(await computeSiloedTagRange(secret, newLogs, 1)); + + const logs = await sync([secret]); + + expect(logs).toHaveLength(newLogs); + // The capped catch-up still drains the run fully. + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(newLogs); + const sizes = callSizes(); + expect(sizes).toEqual(expectedConstrainedProbeRanges(newLogs).map(({ start, end }) => end - start)); + expect(Math.max(...sizes)).toBe(UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN); + expect(sizes.filter(size => size === UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN)).toHaveLength(2); + }); + + it('batches tags from multiple constrained secrets into a single RPC call', async () => { + const secrets = await makeSecrets(3, AppTaggingSecretKind.CONSTRAINED); + mockNodeWithLogs([]); + + await sync(secrets); + + // One batched call carrying exactly each secret's initial probe tag (index 0): constrained secrets share the same + // RPC round as everything else rather than getting a call apiece. + expect(aztecNode.getPrivateLogsByTags).toHaveBeenCalledTimes(1); + expect(calledTags()).toEqual(await Promise.all(secrets.map(s => computeSiloedTagForIndex(s, 0)))); + }); + + it('halts at the first all-miss batch and never probes past the gap', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // Contiguous run 0,1,2 ends at the gap (index 3); a sentinel log sits far past it at index 10. The doubling probe + // reaches the all-miss batch [3..6] and stops there, starting no further round, so index 10 is never queried. The + // sentinel is a falsifying witness: a scan that failed to stop would eventually fetch it. + mockNodeWithLogs(await computeSiloedTags(secret, [0, 1, 2, 10])); + + const logs = await sync([secret]); + + // Only the contiguous prefix is returned, and the sentinel's index was never queried. + expect(logs).toHaveLength(3); + const sentinelTag = await computeSiloedTagForIndex(secret, 10); + expect(allCalledTags().some(t => t.equals(sentinelTag))).toBe(false); + }); + + it('resets the probe to the initial length on the sync after a cap-saturating catch-up', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // A cold-start run deep enough that the first sync doubles the in-memory probe all the way to the WINDOW_LEN + // cap. The probe length lives only on the in-memory PendingSecret, so the next sync must start fresh at the + // initial probe rather than inheriting the saturated one, which would forfeit the steady-state optimization + // after every catch-up. + const totalLogs = UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN * 3; + mockNodeWithLogs(await computeSiloedTagRange(secret, totalLogs)); + + // First sync catches up the whole run; the finalized index lands on the last index and the probe saturated the + // cap along the way. + await sync([secret]); + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(totalLogs - 1); + expect(Math.max(...callSizes())).toBe(UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN); + + // Drop the catch-up's recorded calls (mockClear keeps the implementation; mockReset would not) so the next + // assertions see only the second sync. + aztecNode.getPrivateLogsByTags.mockClear(); + + // Second sync, no new logs: it must probe a single tag at the finalized index + 1, not the saturated probe from + // the catch-up. + await sync([secret]); + expect(aztecNode.getPrivateLogsByTags).toHaveBeenCalledTimes(1); + const probedTags = calledTags(); + expect(probedTags).toHaveLength(INITIAL_CONSTRAINED_PROBE_LEN); + expect(probedTags).toEqual([await computeSiloedTagForIndex(secret, totalLogs)]); }); - it('respects pre-existing finalized index', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.CONSTRAINED); - const existingFinalizedIndex = 5; - await taggingStore.updateHighestFinalizedIndex(secret, existingFinalizedIndex, JOB_ID); + it('steady state probes only the initial probe length in a single round', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + const finalizedIndex = 8; + await taggingStore.updateHighestFinalizedIndex(secret, finalizedIndex, JOB_ID); + mockNodeWithLogs([]); - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => - Promise.resolve(query.tags.map(() => [])), + await sync([secret]); + + // Gapless stream: the first missing tag ends the scan, so steady state costs a single round of a single probe. + expect(aztecNode.getPrivateLogsByTags).toHaveBeenCalledTimes(1); + expect(calledTags()).toEqual( + await computeSiloedTagRange(secret, INITIAL_CONSTRAINED_PROBE_LEN, finalizedIndex + 1), ); + }); - await syncTaggedPrivateLogs([secret], aztecNode, taggingStore, ANCHOR_BLOCK_HEADER, BlockNumber(10), JOB_ID); + // Pins the round-trip growth law the ~log2(K) claim is qualified against: catch-up is logarithmic only while the + // probe is still doubling, then linear at roughly one extra round per WINDOW_LEN once the probe saturates the cap. + it.each([1, 3, 20, 50, 100, UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN * 3])( + 'catch-up round-trips grow logarithmically then linearly: K=%i', + async newLogs => { + // A round queries at most WINDOW_LEN tags (the probe cap) with at most one log per tag, so as long as the cap + // fits in a single RPC, one sync round is exactly one RPC call and the call count is the round-trip count. + expect(UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN).toBeLessThanOrEqual(MAX_RPC_LEN); - const calledTags = extractTags(aztecNode.getPrivateLogsByTags.mock.calls[0][0]); + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + const expectedRounds = expectedConstrainedProbeRanges(newLogs).length; - const expectedStart = existingFinalizedIndex + 1; - const expectedEnd = existingFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN; - const expectedTags = await Promise.all( - Array.from({ length: expectedEnd - expectedStart + 1 }, (_, i) => - computeSiloedTagForIndex(secret, expectedStart + i), - ), + // Recipient already synced index 0; K new contiguous finalized logs sit at indexes 1..K. + await taggingStore.updateHighestFinalizedIndex(secret, 0, JOB_ID); + mockNodeWithLogs(await computeSiloedTagRange(secret, newLogs, 1)); + + const logs = await sync([secret]); + + expect(logs).toHaveLength(newLogs); + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(newLogs); + expect(aztecNode.getPrivateLogsByTags.mock.calls).toHaveLength(expectedRounds); + }, + ); + + // Secrets whose probe misses drop out of the sync and are not re-probed in the rounds a straggler keeps driving. + // This is the unit-level analogue of the bench `mixed` scenario, which the bench (skipped in CI) cannot pin. + it('drops caught-up secrets from later rounds while a straggler keeps syncing', async () => { + const idleSecrets = await makeSecrets(4, AppTaggingSecretKind.CONSTRAINED); + const straggler = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // Idle secrets are caught up at index 5, so their next probe (index 6) misses and drops them after round 1. The + // straggler is at index 0 with 3 new contiguous logs at indexes 1..3. + const idleFinalizedIndex = 5; + for (const secret of idleSecrets) { + await taggingStore.updateHighestFinalizedIndex(secret, idleFinalizedIndex, JOB_ID); + } + await taggingStore.updateHighestFinalizedIndex(straggler, 0, JOB_ID); + mockNodeWithLogs(await computeSiloedTags(straggler, [1, 2, 3])); + + const logs = await sync([...idleSecrets, straggler]); + expect(logs).toHaveLength(3); + + // Round 1: 4 idle probes + straggler[1]. Rounds 2 and 3 are straggler-only: [2,3], then [4..7] (terminating + // miss at 4). + expect(callSizes()).toEqual([5, 2, 4]); + expect(await taggingStore.getHighestFinalizedIndex(straggler, JOB_ID)).toBe(3); + + // Dropping out also means no writes: the caught-up secrets' finalized indexes are untouched by the + // straggler-driven rounds. + for (const secret of idleSecrets) { + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(idleFinalizedIndex); + } + }); + }); + + describe('fully drains a cold-start run longer than the window', () => { + const totalLogs = UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 2; + + it('constrained', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + + // A cold-start run two indexes past one window. Reaching the tail is only possible because the scan bound + // re-anchors forward to each finalized index found. + mockNodeWithLogs(await computeSiloedTagRange(secret, totalLogs)); + + const logs = await sync([secret]); + + // The whole run is returned and the finalized index lands on the last index, even though the run is longer than + // a single window. + expect(logs).toHaveLength(totalLogs); + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(totalLogs - 1); + + // The final round reaches past the initial cold-start bound only because the bound re-anchored forward. + const expectedRanges = expectedConstrainedProbeRanges(totalLogs, 0); + expect(callSizes()).toEqual(expectedRanges.map(({ start, end }) => end - start)); + const lastRange = expectedRanges[expectedRanges.length - 1]; + expect(calledTags(expectedRanges.length - 1)).toEqual( + await computeSiloedTagRange(secret, lastRange.end - lastRange.start, lastRange.start), ); + expect(lastRange.end - 1).toBeGreaterThan(UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN); + }); + + it('unconstrained', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); + + // The same run as the constrained case, but gaps are possible so there is no first-miss stop and no doubling + // probe: every round covers a full window. + mockNodeWithLogs(await computeSiloedTagRange(secret, totalLogs)); - expect(calledTags).toEqual(expectedTags); + const logs = await sync([secret]); + + // Every log is returned and both stored indexes land on the last index. The aged index advances since the logs + // are old enough, unlike a constrained secret, which never tracks an aged index. + expect(logs).toHaveLength(totalLogs); + expect(await taggingStore.getHighestFinalizedIndex(secret, JOB_ID)).toBe(totalLogs - 1); + expect(await taggingStore.getHighestAgedIndex(secret, JOB_ID)).toBe(totalLogs - 1); + + // The first round spans the full cold-start window (WINDOW_LEN + 1). Because every index hit, the next round + // re-anchors to another full WINDOW_LEN window ahead of the new finalized index: no small initial probe and no + // doubling, in contrast to the constrained scan. + expect(callSizes().slice(0, 2)).toEqual([ + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1, + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN, + ]); }); }); describe('mixed constrained and unconstrained secrets', () => { it('batches both kinds into a single RPC call with different stop conditions', async () => { - const [constrainedSecret] = await makeSecrets(1, AppTaggingSecretKind.CONSTRAINED); - const [unconstrainedSecret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; - - const constrainedLogTags = await Promise.all([0, 1].map(i => computeSiloedTagForIndex(constrainedSecret, i))); - const unconstrainedLogTags = await Promise.all([0, 5].map(i => computeSiloedTagForIndex(unconstrainedSecret, i))); - - aztecNode.getPrivateLogsByTags.mockImplementation((query: PrivateLogsQuery) => { - const tags = extractTags(query); - return Promise.resolve( - tags.map((t: SiloedTag) => { - const cMatch = constrainedLogTags.find(tag => tag.equals(t)); - const uMatch = unconstrainedLogTags.find(tag => tag.equals(t)); - if (cMatch || uMatch) { - return [makeLog(Number(finalizedBlockNumber), logBlockTimestamp, t.value)]; - } - return []; - }), - ); - }); - - const logs = await syncTaggedPrivateLogs( - [constrainedSecret, unconstrainedSecret], - aztecNode, - taggingStore, - ANCHOR_BLOCK_HEADER, - finalizedBlockNumber, - JOB_ID, - ); + const constrainedSecret = await randomAppTaggingSecret(AppTaggingSecretKind.CONSTRAINED); + const unconstrainedSecret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); + + mockNodeWithLogs([ + ...(await computeSiloedTags(constrainedSecret, [0, 1])), + ...(await computeSiloedTags(unconstrainedSecret, [0, 5])), + ]); + + const logs = await sync([constrainedSecret, unconstrainedSecret]); expect(logs).toHaveLength(4); expect(await taggingStore.getHighestFinalizedIndex(constrainedSecret, JOB_ID)).toBe(1); expect(await taggingStore.getHighestAgedIndex(constrainedSecret, JOB_ID)).toBeUndefined(); expect(await taggingStore.getHighestFinalizedIndex(unconstrainedSecret, JOB_ID)).toBe(5); + + // Both kinds share one batched query rather than one query per kind. + const firstCallTags = calledTags(); + const constrainedProbeTag = await computeSiloedTagForIndex(constrainedSecret, 0); + const unconstrainedProbeTag = await computeSiloedTagForIndex(unconstrainedSecret, 0); + expect(firstCallTags.some(t => t.equals(constrainedProbeTag))).toBe(true); + expect(firstCallTags.some(t => t.equals(unconstrainedProbeTag))).toBe(true); }); }); - it('caps the node query at anchorBlockNumber + 1 (toBlock exclusive)', async () => { - const [secret] = await makeSecrets(1, AppTaggingSecretKind.UNCONSTRAINED); + it('caps the node query to blocks at or before the anchor block', async () => { + const secret = await randomAppTaggingSecret(AppTaggingSecretKind.UNCONSTRAINED); const anchorBlock = BlockNumber(10); const header = BlockHeader.random({ blockNumber: anchorBlock, timestamp: CURRENT_TIMESTAMP }); - const finalizedBlockNumber = BlockNumber(10); - const logBlockTimestamp = CURRENT_TIMESTAMP - BigInt(MAX_TX_LIFETIME) - 1000n; - - const logIndex = 3; - const logTag = await computeSiloedTagForIndex(secret, logIndex); + const logTag = await computeSiloedTagForIndex(secret, 3); // The mock simulates the node honoring `toBlock` (exclusive). Recipient sync now relies on the node // for this filter rather than dropping post-anchor logs client-side. @@ -429,9 +602,9 @@ describe('syncTaggedPrivateLogs', () => { const tags = extractTags(query); const toBlockExclusive = Number(query.toBlock ?? Infinity); const allCandidates = [ - makeLog(Number(anchorBlock) - 1, logBlockTimestamp, logTag.value), - makeLog(Number(anchorBlock), logBlockTimestamp, logTag.value), - makeLog(Number(anchorBlock) + 1, logBlockTimestamp, logTag.value), + makeLog(Number(anchorBlock) - 1, AGED_TIMESTAMP), + makeLog(Number(anchorBlock), AGED_TIMESTAMP), + makeLog(Number(anchorBlock) + 1, AGED_TIMESTAMP), ]; return Promise.resolve( tags.map((t: SiloedTag) => @@ -440,7 +613,7 @@ describe('syncTaggedPrivateLogs', () => { ); }); - const logs = await syncTaggedPrivateLogs([secret], aztecNode, taggingStore, header, finalizedBlockNumber, JOB_ID); + const logs = await sync([secret], FINALIZED_BLOCK_NUMBER, header); // Only logs at or before the anchor block should be included — node-side filter drops the post-anchor log. expect(logs).toHaveLength(2); @@ -450,5 +623,5 @@ describe('syncTaggedPrivateLogs', () => { }); function makeSecrets(count: number, kind: AppTaggingSecretKind): Promise { - return Promise.all(Array.from({ length: count }, () => randomAppTaggingSecret(kind))); + return timesParallel(count, () => randomAppTaggingSecret(kind)); } diff --git a/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.ts b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.ts index c2aeeededcf4..eed87a9745d9 100644 --- a/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.ts +++ b/yarn-project/pxe/src/tagging/recipient_sync/sync_tagged_private_logs.ts @@ -7,7 +7,7 @@ import { AppTaggingSecretKind, SiloedTag } from '@aztec/stdlib/logs'; import type { BlockHeader } from '@aztec/stdlib/tx'; import type { RecipientTaggingStore } from '../../storage/tagging_store/recipient_tagging_store.js'; -import { UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN } from '../constants.js'; +import { INITIAL_CONSTRAINED_PROBE_LEN, UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN } from '../constants.js'; import { getAllPrivateLogsByTags } from '../get_all_logs_by_tags.js'; import { findHighestIndexes } from './utils/find_highest_indexes.js'; @@ -62,9 +62,16 @@ import { findHighestIndexes } from './utils/find_highest_indexes.js'; * - The lower bound is `highestFinalizedIndex + 1`. The `highestAgedIndex` mechanism is unnecessary because * the nullifier chain prevents out-of-order index usage: no device can fill in a lower index after a higher * one is already on-chain. - * - The scan stops at the first gap in the index sequence. If all indexes in the batch have logs, the window - * advances. If a gap is found, the sequence has ended and no further logs exist. - * - The upper bound is the same as unconstrained: `highestFinalizedIndex + WINDOW_LEN`. + * - Because the sequence is gapless, the scan stops at the first missing index: that gap proves the sequence has + * ended and no further logs exist. We exploit this by probing only a small initial window + * (`INITIAL_CONSTRAINED_PROBE_LEN`) and doubling it each round (capped at the window) while every probed index has a + * log, stopping at the first miss. A steady-state sync with no new logs costs a single tag instead of the whole + * window. A secret K logs behind catches up in ~log2(K) round-trips while the probe is still doubling, then linearly + * at ~K/WINDOW_LEN rounds once the probe saturates the cap, still far below one round per log. The probe length is + * in-memory state scoped to one sync call, so every sync restarts at the initial probe. + * - The upper bound is the same as unconstrained: `highestFinalizedIndex + WINDOW_LEN`. Advancing the probe is + * decoupled from persisting the finalized index, so unfinalized logs at the top of the run are still fetched + * while only the finalized prefix is persisted. * * # Batching across secrets * @@ -147,9 +154,19 @@ function getIndexRangesForSecrets( : await taggingStore.getHighestAgedIndex(secret, jobId); const start = highestIndexBeforeStart === undefined ? 0 : highestIndexBeforeStart + 1; - const end = (currentHighestFinalizedIndex ?? 0) + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1; + const boundEnd = (currentHighestFinalizedIndex ?? 0) + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1; - return { secret, start, end }; + // Constrained streams are gapless, so probe a small initial window and stop at the first missing tag instead of + // always fetching the full window. Unconstrained secrets can have gaps, so they still scan the whole window. + const end = + secret.kind === AppTaggingSecretKind.CONSTRAINED + ? Math.min(boundEnd, start + INITIAL_CONSTRAINED_PROBE_LEN) + : boundEnd; + + // Constrained-only: continued probes grow each round up to the window cap (see processConstrainedResults). + const probeLen = secret.kind === AppTaggingSecretKind.CONSTRAINED ? INITIAL_CONSTRAINED_PROBE_LEN : undefined; + + return { secret, start, end, boundEnd, probeLen }; }), ); } @@ -203,8 +220,8 @@ async function fetchLogsForSecrets( } /** - * Processes fetched logs for a constrained secret. Constrained delivery guarantees contiguous index sequences, - * so we scan from the start of the queried range and stop at the first missing index. Only `highestFinalizedIndex` + * Processes fetched logs for a constrained secret: persists the finalized index and advances the probe. See the + * "# Constrained secrets" section above for why the scan stops at the first missing index. Only `highestFinalizedIndex` * is tracked (no aged index). */ async function processConstrainedResults( @@ -215,29 +232,46 @@ async function processConstrainedResults( finalizedBlockNumber: BlockNumber, jobId: string, ): Promise { - // Find where the contiguous run of indexes ends. Constrained delivery guarantees there are no logs after the - // first gap, so all logs in the batch are within this prefix. + // Find where the contiguous run of indexes ends; all logs in the batch fall within this prefix. const indexesWithLogs = new Set(logsWithIndexes.map(l => l.taggingIndex)); let firstMissingIndex = pending.start; while (firstMissingIndex < pending.end && indexesWithLogs.has(firstMissingIndex)) { firstMissingIndex++; } - // Finalize any logs before the gap. The nullifier for a constrained-delivery log is emitted in the same - // transaction, guaranteeing the log cannot disappear once included, so we persist the highest finalized - // index even when a gap stops the scan. This lets the next sync round skip already-finalized indexes. + // Persist the highest finalized index found. The nullifier for a constrained-delivery log is emitted in the same + // transaction, guaranteeing the log cannot disappear once included, so we persist even when a gap stops the scan. + // This lets the next sync round skip already-finalized indexes. const { highestFinalizedIndex } = findHighestIndexes(logsWithIndexes, currentTimestamp, finalizedBlockNumber); - if (highestFinalizedIndex !== undefined) { await taggingStore.updateHighestFinalizedIndex(pending.secret, highestFinalizedIndex, jobId); + } - if (firstMissingIndex >= pending.end) { - return { - secret: pending.secret, - start: pending.end, - end: highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1, - }; - } + // Advancing the probe is decoupled from persisting the finalized index: keep scanning as long as the probe was + // entirely hits (no gap) and there is room before the protocol bound, even if none of those hits is finalized yet. + // Gating this on finalization would drop logs in unfinalized blocks, which sit at the top of the contiguous run. + // The bound re-anchors to any finalized index found this round. + const probeFullyConsumed = firstMissingIndex >= pending.end; + const boundEnd = + highestFinalizedIndex !== undefined + ? Math.max(pending.boundEnd, highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1) + : pending.boundEnd; + + // Double the probe each round so catch-up costs ~log2(K) round-trips while the probe is still doubling, then + // ~K/WINDOW_LEN once it saturates the cap, far below one round per log either way. The queried range is already + // bounded by boundEnd (a probe can never reach more than WINDOW_LEN past the finalized frontier); the cap on the + // stored length just keeps it from growing unbounded once the probe saturates the window. + const currentProbeLen = pending.probeLen ?? INITIAL_CONSTRAINED_PROBE_LEN; + const nextProbeLen = Math.min(currentProbeLen * 2, UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN); + + if (probeFullyConsumed && pending.end < boundEnd) { + return { + secret: pending.secret, + start: pending.end, + end: Math.min(boundEnd, pending.end + nextProbeLen), + boundEnd, + probeLen: nextProbeLen, + }; } return undefined; @@ -282,10 +316,12 @@ async function processUnconstrainedResults( // For the next iteration we want to look only at indexes for which we have not yet fetched logs while // ensuring that we do not look further than WINDOW_LEN ahead of the highest finalized index. + const end = highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1; return { secret: pending.secret, start: pending.end, - end: highestFinalizedIndex + UNFINALIZED_TAGGING_INDEXES_WINDOW_LEN + 1, + end, + boundEnd: end, }; } @@ -293,6 +329,12 @@ type PendingSecret = { secret: AppTaggingSecret; start: number; end: number; + // Exclusive upper bound on the indexes this secret may probe this sync (highest finalized index + WINDOW_LEN + 1, the + // protocol bound on how far ahead of finalized a log can sit). Constrained `end` grows toward it each round. + boundEnd: number; + // Intended constrained probe length for the round that produced `end` (constrained-only). The queried span can be + // smaller when boundEnd caps it. + probeLen?: number; }; type LogWithIndex = {