{simulationResults?.success ? (
{simulationResults?.data ?? 'No return value'}
) : (
@@ -281,7 +289,11 @@ export function FunctionCard({ fn, contract, contractArtifact, onSendTxRequested
<>
diff --git a/yarn-project/cli-wallet/src/utils/profiling.ts b/yarn-project/cli-wallet/src/utils/profiling.ts
index e14be66ca1e3..eb94f22f0390 100644
--- a/yarn-project/cli-wallet/src/utils/profiling.ts
+++ b/yarn-project/cli-wallet/src/utils/profiling.ts
@@ -95,7 +95,7 @@ export function printProfileResult(
if (stats.nodeRPCCalls) {
log(format('\nRPC calls:\n'));
- for (const [method, { times }] of Object.entries(stats.nodeRPCCalls)) {
+ for (const [method, { times }] of Object.entries(stats.nodeRPCCalls.perMethod)) {
const calls = times.length;
const total = times.reduce((acc, time) => acc + time, 0);
const avg = total / calls;
@@ -112,6 +112,20 @@ export function printProfileResult(
),
);
}
+
+ const { roundTrips } = stats.nodeRPCCalls;
+ log(format('\nRound trips (actual blocking waits):\n'));
+ log(format('Round trips:'.padEnd(25), `${roundTrips.roundTrips}`.padStart(COLUMN_MAX_WIDTH)));
+ log(
+ format(
+ 'Total blocking time:'.padEnd(25),
+ `${roundTrips.totalBlockingTime.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
+ ),
+ );
+ if (roundTrips.roundTrips > 0) {
+ const avgRoundTrip = roundTrips.totalBlockingTime / roundTrips.roundTrips;
+ log(format('Avg round trip:'.padEnd(25), `${avgRoundTrip.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH)));
+ }
}
log(format('\nSync time:'.padEnd(25), `${timings.sync?.toFixed(2)}ms`.padStart(16)));
diff --git a/yarn-project/end-to-end/src/bench/client_flows/amm.test.ts b/yarn-project/end-to-end/src/bench/client_flows/amm.test.ts
index 79283b631bdd..8e057945b9de 100644
--- a/yarn-project/end-to-end/src/bench/client_flows/amm.test.ts
+++ b/yarn-project/end-to-end/src/bench/client_flows/amm.test.ts
@@ -6,6 +6,7 @@ import { AMMContract } from '@aztec/noir-contracts.js/AMM';
import { FPCContract } from '@aztec/noir-contracts.js/FPC';
import { SponsoredFPCContract } from '@aztec/noir-contracts.js/SponsoredFPC';
import { TokenContract } from '@aztec/noir-contracts.js/Token';
+import type { RoundTripStats } from '@aztec/stdlib/tx';
import type { TestWallet } from '@aztec/test-wallet/server';
import { jest } from '@jest/globals';
@@ -20,7 +21,25 @@ const AMOUNT_PER_NOTE = 1_000_000;
const MINIMUM_NOTES_FOR_RECURSION_LEVEL = [0, 2, 10];
+// Set to true to print out the round trip information to the console.
+const DEBUG_ROUND_TRIPS = true;
+
+// Expected number of node round trips per account contract and payment method.
+const EXPECTED_ROUND_TRIPS: Record = {
+ 'ecdsar1+private_fpc': 118,
+ 'ecdsar1+sponsored_fpc': 80,
+ 'schnorr+private_fpc': 118,
+ 'schnorr+sponsored_fpc': 82,
+};
+
+interface RoundTripData {
+ accountType: AccountType;
+ paymentMethod: BenchmarkingFeePaymentMethod;
+ roundTrips: RoundTripStats | undefined;
+}
+
describe('AMM benchmark', () => {
+ const roundTripData: RoundTripData[] = [];
const t = new ClientFlowsBenchmark('amm');
// The wallet used by the admin to interact
let adminWallet: Wallet;
@@ -70,6 +89,9 @@ describe('AMM benchmark', () => {
});
afterAll(async () => {
+ if (DEBUG_ROUND_TRIPS) {
+ printRoundTripDebuggingInfo(roundTripData);
+ }
await t.teardown();
});
@@ -158,7 +180,7 @@ describe('AMM benchmark', () => {
.methods.add_liquidity(amountToSend, amountToSend, amountToSend, amountToSend, nonceForAuthwits)
.with({ authWitnesses: [token0Authwit, token1Authwit] });
- await captureProfile(
+ const profileResult = await captureProfile(
`${accountType}+amm_add_liquidity_1_recursions+${benchmarkingPaymentMethod}`,
addLiquidityInteraction,
options,
@@ -180,6 +202,36 @@ describe('AMM benchmark', () => {
const tx = await addLiquidityInteraction.send({ from: benchysAddress }).wait();
expect(tx.transactionFee!).toBeGreaterThan(0n);
}
+
+ if (DEBUG_ROUND_TRIPS) {
+ roundTripData.push({
+ accountType,
+ paymentMethod: benchmarkingPaymentMethod,
+ roundTrips: profileResult.stats.nodeRPCCalls?.roundTrips,
+ });
+ } else {
+ const roundTripsKey = `${accountType}+${benchmarkingPaymentMethod}`;
+ const actualRoundTrips = profileResult.stats.nodeRPCCalls?.roundTrips.roundTrips ?? 0;
+ const expectedRoundTrips = EXPECTED_ROUND_TRIPS[roundTripsKey];
+ if (expectedRoundTrips === undefined) {
+ throw new Error(
+ `Missing expected round trips for ${roundTripsKey}. ` +
+ `Add '${roundTripsKey}': ${actualRoundTrips} to EXPECTED_ROUND_TRIPS.`,
+ );
+ }
+
+ // The following check serves as a regression test. If you get a failure and it is expected, just update
+ // the EXPECTED_ROUND_TRIPS constants. If the failure is unexpected, it needs to be investigated. To
+ // investigate, set the DEBUG_ROUND_TRIPS environment variable to true on both the `next` branch and
+ // here, then compare the outputs (look for any newly appearing or missing round trips). To compare the
+ // outputs I recommend using a diff checker like https://www.diffchecker.com/.
+ //
+ // Note that the round trip values depend on this test suite being run in its entirety and in the correct
+ // order.
+ //
+ // If you encounter this failure in CI and are unsure of the cause, contact @benesjan.
+ expect(actualRoundTrips).toBe(expectedRoundTrips);
+ }
});
});
}
@@ -189,4 +241,134 @@ describe('AMM benchmark', () => {
}
});
}
+
+ /**
+ * Prints out the round trip information that can be used to debug unexpected round trip changes.
+ */
+ function printRoundTripDebuggingInfo(data: RoundTripData[]) {
+ for (const trip of data) {
+ if (!trip.roundTrips) {
+ throw new Error(
+ `Round trip stats are undefined for ${trip.accountType}+${trip.paymentMethod}. This should not happen.`,
+ );
+ }
+ }
+
+ const width = 120; // Fixed standard width
+ const title = ' ROUND TRIP DEBUGGING INFORMATION';
+
+ // Helper function to wrap long lines, breaking at commas when possible
+ function wrapLine(content: string, maxContentWidth: number): string[] {
+ if (content.length <= maxContentWidth) {
+ return [content];
+ }
+
+ const lines: string[] = [];
+ let remaining = content;
+
+ while (remaining.length > 0) {
+ if (remaining.length <= maxContentWidth) {
+ lines.push(remaining);
+ break;
+ }
+
+ // Try to find a good break point (comma followed by space)
+ let breakPoint = maxContentWidth;
+ const commaIndex = remaining.lastIndexOf(', ', maxContentWidth);
+ if (commaIndex > maxContentWidth * 0.4) {
+ // Use comma break if it's not too early (at least 40% into the line)
+ breakPoint = commaIndex + 2; // Include the comma and space
+ }
+
+ const line = remaining.substring(0, breakPoint);
+ lines.push(line);
+ remaining = remaining.substring(breakPoint).trim();
+ }
+
+ return lines;
+ }
+
+ // Group by account type for better organization
+ const groupedByAccount = data.reduce(
+ (acc, item) => {
+ if (!acc[item.accountType]) {
+ acc[item.accountType] = [];
+ }
+ acc[item.accountType].push(item);
+ return acc;
+ },
+ {} as Record,
+ );
+
+ const accountEntries = Object.entries(groupedByAccount) as [AccountType, RoundTripData[]][];
+ const topBorder = '╔' + '═'.repeat(width - 2) + '╗';
+ const bottomBorder = '╚' + '═'.repeat(width - 2) + '╝';
+ const sectionTop = '╠' + '═'.repeat(width - 2) + '╣';
+ const sectionDivider = '╠' + '─'.repeat(width - 2) + '╣';
+ const sectionBottom = '╠' + '─'.repeat(width - 2) + '╣';
+ const leftBorder = '║';
+ const rightBorder = '║';
+
+ let output = '\n' + topBorder + '\n';
+ output += leftBorder + title.padEnd(width - 2) + rightBorder + '\n';
+ output += sectionTop + '\n';
+
+ for (let accountIdx = 0; accountIdx < accountEntries.length; accountIdx++) {
+ const [accountType, items] = accountEntries[accountIdx];
+
+ if (accountIdx > 0) {
+ output += sectionDivider + '\n';
+ }
+
+ output += leftBorder + ` Account Type: ${accountType.toUpperCase()}`.padEnd(width - 2) + rightBorder + '\n';
+ output += sectionDivider + '\n';
+
+ for (let itemIdx = 0; itemIdx < items.length; itemIdx++) {
+ const item = items[itemIdx];
+
+ if (!item.roundTrips) {
+ throw new Error(
+ `Round trip stats are undefined for ${item.accountType}+${item.paymentMethod}. This should not happen.`,
+ );
+ }
+ const roundTrips = item.roundTrips; // TypeScript now knows it's defined
+
+ if (itemIdx > 0) {
+ output += leftBorder + ' '.repeat(width - 2) + rightBorder + '\n';
+ }
+
+ const key = `${item.accountType}+${item.paymentMethod}`;
+ output += leftBorder + ` Configuration: ${key}`.padEnd(width - 2) + rightBorder + '\n';
+ output += leftBorder + ` Total Round Trips: ${roundTrips.roundTrips}`.padEnd(width - 2) + rightBorder + '\n';
+ output += leftBorder + ` Payment Method: ${item.paymentMethod}`.padEnd(width - 2) + rightBorder + '\n';
+ output += leftBorder + ' '.repeat(width - 2) + rightBorder + '\n';
+ output += leftBorder + ' Per Round Trip:'.padEnd(width - 2) + rightBorder + '\n';
+
+ for (let i = 0; i < roundTrips.roundTripMethods.length; i++) {
+ const methods = roundTrips.roundTripMethods[i];
+ const methodsStr = methods.length > 0 ? methods.join(', ') : '(empty)';
+ const rtNum = String(i + 1).padStart(3, ' ');
+ const prefix = ` RT ${rtNum}: `;
+ const content = `[${methodsStr}]`;
+
+ // Calculate available width for content (account for borders and prefix)
+ // width - 2 for borders, then subtract prefix length
+ const maxContentWidth = width - 2 - prefix.length;
+ const wrappedLines = wrapLine(content, maxContentWidth);
+
+ for (let lineIdx = 0; lineIdx < wrappedLines.length; lineIdx++) {
+ const lineContent = lineIdx === 0 ? prefix + wrappedLines[lineIdx] : ' ' + wrappedLines[lineIdx]; // Continuation line with extra indentation
+ output += leftBorder + lineContent.padEnd(width - 2) + rightBorder + '\n';
+ }
+ }
+ }
+ }
+
+ output += sectionBottom + '\n';
+ output += leftBorder + ` Total Test Runs: ${data.length}`.padEnd(width - 2) + rightBorder + '\n';
+ output += bottomBorder + '\n';
+
+ // eslint-disable-next-line no-console
+ console.log(output);
+ }
});
diff --git a/yarn-project/end-to-end/src/bench/client_flows/benchmark.ts b/yarn-project/end-to-end/src/bench/client_flows/benchmark.ts
index 44d82bdf5fdc..34aa59e74fc5 100644
--- a/yarn-project/end-to-end/src/bench/client_flows/benchmark.ts
+++ b/yarn-project/end-to-end/src/bench/client_flows/benchmark.ts
@@ -7,7 +7,13 @@ import {
import type { Logger } from '@aztec/aztec.js/log';
import { createLogger } from '@aztec/foundation/log';
import { type PrivateExecutionStep, serializePrivateExecutionSteps } from '@aztec/stdlib/kernel';
-import type { ProvingStats, ProvingTimings, SimulationStats, SimulationTimings } from '@aztec/stdlib/tx';
+import type {
+ ProvingStats,
+ ProvingTimings,
+ RoundTripStats,
+ SimulationStats,
+ SimulationTimings,
+} from '@aztec/stdlib/tx';
import assert from 'node:assert';
import { mkdir, writeFile } from 'node:fs/promises';
@@ -119,6 +125,7 @@ type ClientFlowBenchmark = {
timings: Omit & { witgen: number };
maxMemory: number;
rpc: Record;
+ roundTrips: RoundTripStats;
proverType: ProverType;
minimumTrace: StructuredTrace;
totalGateCount: number;
@@ -212,6 +219,10 @@ export function generateBenchmark(
}, []);
const timings = stats.timings;
const totalGateCount = steps[steps.length - 1].accGateCount;
+ const nodeRPCCalls = stats.nodeRPCCalls ?? {
+ perMethod: {},
+ roundTrips: { roundTrips: 0, totalBlockingTime: 0, roundTripDurations: [], roundTripMethods: [] },
+ };
return {
name: flow,
timings: {
@@ -221,7 +232,7 @@ export function generateBenchmark(
unaccounted: timings.unaccounted,
witgen: timings.perFunction.reduce((acc, fn) => acc + fn.time, 0),
},
- rpc: Object.entries(stats.nodeRPCCalls ?? {}).reduce(
+ rpc: Object.entries(nodeRPCCalls.perMethod).reduce(
(acc, [RPCName, RPCCalls]) => {
const total = RPCCalls.times.reduce((sum, time) => sum + time, 0);
const calls = RPCCalls.times.length;
@@ -236,6 +247,7 @@ export function generateBenchmark(
},
{} as Record,
),
+ roundTrips: nodeRPCCalls.roundTrips,
maxMemory,
proverType,
minimumTrace: minimumTrace!,
@@ -280,6 +292,16 @@ export function convertProfileToGHBenchmark(benchmark: ClientFlowBenchmark): Git
value: totalRPCCalls,
unit: 'calls',
},
+ {
+ name: `${benchmark.name}/round_trips`,
+ value: benchmark.roundTrips.roundTrips,
+ unit: 'round_trips',
+ },
+ {
+ name: `${benchmark.name}/round_trips_blocking_time`,
+ value: benchmark.roundTrips.totalBlockingTime,
+ unit: 'ms',
+ },
];
if (benchmark.timings.proving) {
benches.push({
diff --git a/yarn-project/pxe/src/contract_function_simulator/contract_function_simulator.ts b/yarn-project/pxe/src/contract_function_simulator/contract_function_simulator.ts
index 3b17d54f1553..01e2fe9f82e2 100644
--- a/yarn-project/pxe/src/contract_function_simulator/contract_function_simulator.ts
+++ b/yarn-project/pxe/src/contract_function_simulator/contract_function_simulator.ts
@@ -331,7 +331,12 @@ export class ContractFunctionSimulator {
*/
getStats() {
const nodeRPCCalls =
- typeof (this.aztecNode as ProxiedNode).getStats === 'function' ? (this.aztecNode as ProxiedNode).getStats() : {};
+ typeof (this.aztecNode as ProxiedNode).getStats === 'function'
+ ? (this.aztecNode as ProxiedNode).getStats()
+ : {
+ perMethod: {},
+ roundTrips: { roundTrips: 0, totalBlockingTime: 0, roundTripDurations: [], roundTripMethods: [] },
+ };
return { nodeRPCCalls };
}
diff --git a/yarn-project/pxe/src/contract_function_simulator/proxied_node.ts b/yarn-project/pxe/src/contract_function_simulator/proxied_node.ts
index 65ea8cfb80ac..039bad515e08 100644
--- a/yarn-project/pxe/src/contract_function_simulator/proxied_node.ts
+++ b/yarn-project/pxe/src/contract_function_simulator/proxied_node.ts
@@ -1,30 +1,100 @@
import { Timer } from '@aztec/foundation/timer';
import type { AztecNode } from '@aztec/stdlib/interfaces/client';
-import type { NodeStats } from '@aztec/stdlib/tx';
+import type { NodeStats, RoundTripStats } from '@aztec/stdlib/tx';
/*
- * Proxy generator for an AztecNode that tracks the time taken for each RPC call.
+ * Proxy generator for an AztecNode that tracks the time taken for each RPC call and the number of round trips (actual
+ * blocking waits for node responses).
+ *
+ * A round trip is counted when we transition from 0 to 1 in-flight calls, and ends when all concurrent calls complete.
+ * This means parallel calls in Promise.all count as a single round trip.
+ *
+ * Note that batching of RPC calls in `safe_json_rpc_client.ts` could affect the round trip counts but in places we
+ * currently use this information we do not even use HTTP as we have direct access to the Aztec Node instance in TS
+ * (i.e. not running against external node) so this is not a problem for now.
+ *
+ * If you want to use this against external node and the info gets skewed by batching you can set the `maxBatchSize`
+ * value in `safe_json_rpc_client.ts` to 1 (the main motivation for batching was to get around parallel http requests
+ * limits in web browsers which is not a problem when debugging in node.js).
*/
export type ProxiedNode = AztecNode & { getStats(): NodeStats };
export class ProxiedNodeFactory {
- static create(node: AztecNode) {
- const stats: Partial> = {};
+ static create(node: AztecNode): ProxiedNode {
+ // Per-method call stats
+ const perMethod: Partial> = {};
+
+ // Round trip tracking
+ let inFlightCount = 0;
+ let currentRoundTripTimer: Timer | null = null;
+ let currentRoundTripMethods: string[] = [];
+ const roundTrips: RoundTripStats = {
+ roundTrips: 0,
+ totalBlockingTime: 0,
+ roundTripDurations: [],
+ roundTripMethods: [],
+ };
+
return new Proxy(node, {
get(target, prop: keyof ProxiedNode) {
if (prop === 'getStats') {
- return () => {
- return stats;
+ return (): NodeStats => {
+ return { perMethod, roundTrips };
};
} else {
- return async function (...args: any[]) {
- if (!stats[prop]) {
- stats[prop] = { times: [] };
+ return function (...args: any[]) {
+ // Track per-method stats
+ if (!perMethod[prop]) {
+ perMethod[prop] = { times: [] };
+ }
+
+ // Start of a new round trip batch?
+ if (inFlightCount === 0) {
+ roundTrips.roundTrips++;
+ currentRoundTripTimer = new Timer();
+ currentRoundTripMethods = [];
+ }
+ inFlightCount++;
+ currentRoundTripMethods.push(prop);
+
+ const callTimer = new Timer();
+ const result = (target[prop] as any).apply(target, args);
+
+ // Handle completion - called when the call finishes (after Promise resolves)
+ const handleCompletion = () => {
+ const callTime = callTimer.ms();
+ perMethod[prop]!.times.push(callTime);
+
+ inFlightCount--;
+
+ // End of round trip batch - all concurrent calls completed
+ if (inFlightCount === 0 && currentRoundTripTimer) {
+ const roundTripTime = currentRoundTripTimer.ms();
+ roundTrips.totalBlockingTime += roundTripTime;
+ roundTrips.roundTripDurations.push(roundTripTime);
+ roundTrips.roundTripMethods.push(currentRoundTripMethods);
+ currentRoundTripTimer = null;
+ currentRoundTripMethods = [];
+ }
+ };
+
+ // If the result is a Promise, chain the completion handler
+ if (result && typeof result.then === 'function') {
+ return result.then(
+ (value: any) => {
+ handleCompletion();
+ return value;
+ },
+ (error: any) => {
+ handleCompletion();
+ throw error;
+ },
+ );
+ } else {
+ // Synchronous method - handle completion immediately
+ handleCompletion();
+ return result;
}
- const timer = new Timer();
- const result = await (target[prop] as any).apply(target, args);
- stats[prop].times.push(timer.ms());
- return result;
};
}
},
diff --git a/yarn-project/stdlib/src/tx/profiling.ts b/yarn-project/stdlib/src/tx/profiling.ts
index be2271654f4b..093e7af471ed 100644
--- a/yarn-project/stdlib/src/tx/profiling.ts
+++ b/yarn-project/stdlib/src/tx/profiling.ts
@@ -6,9 +6,35 @@ import { z } from 'zod';
import type { AztecNode } from '../interfaces/aztec-node.js';
import { type PrivateExecutionStep, PrivateExecutionStepSchema } from '../kernel/private_kernel_prover_output.js';
-export type NodeStats = Partial>;
+export type RoundTripStats = {
+ /** Number of round trips (times we blocked waiting for node responses) */
+ roundTrips: number;
+ /** Total wall-clock time spent waiting on node (excludes parallel overlap) */
+ totalBlockingTime: number;
+ /** Individual round trip durations */
+ roundTripDurations: number[];
+ /** Methods called in each round trip (parallel calls grouped together) */
+ roundTripMethods: string[][];
+};
+
+const RoundTripStatsSchema = z.object({
+ roundTrips: z.number(),
+ totalBlockingTime: z.number(),
+ roundTripDurations: z.array(z.number()),
+ roundTripMethods: z.array(z.array(z.string())),
+});
+
+export type NodeStats = {
+ /** Per-method call stats */
+ perMethod: Partial>;
+ /** Round trip stats tracking actual blocking waits */
+ roundTrips: RoundTripStats;
+};
-const NodeStatsSchema = z.record(z.string(), z.object({ times: z.array(z.number()) }));
+const NodeStatsSchema = z.object({
+ perMethod: z.record(z.string(), z.object({ times: z.array(z.number()) })),
+ roundTrips: RoundTripStatsSchema,
+});
type FunctionTiming = {
functionName: string;
@@ -105,7 +131,15 @@ export class TxProfileResult {
},
],
{
- nodeRPCCalls: { getBlockHeader: { times: [1] } },
+ nodeRPCCalls: {
+ perMethod: { getBlockHeader: { times: [1] } },
+ roundTrips: {
+ roundTrips: 1,
+ totalBlockingTime: 1,
+ roundTripDurations: [1],
+ roundTripMethods: [['getBlockHeader']],
+ },
+ },
timings: {
sync: 1,
proving: 1,
@@ -140,7 +174,15 @@ export class UtilitySimulationResult {
static random(): UtilitySimulationResult {
return new UtilitySimulationResult([Fr.random()], {
- nodeRPCCalls: { getBlockHeader: { times: [1] } },
+ nodeRPCCalls: {
+ perMethod: { getBlockHeader: { times: [1] } },
+ roundTrips: {
+ roundTrips: 1,
+ totalBlockingTime: 1,
+ roundTripDurations: [1],
+ roundTripMethods: [['getBlockHeader']],
+ },
+ },
timings: {
sync: 1,
publicSimulation: 1,