chore: capture RPC calls + correct timings

yarn-project/aztec.js/src/contract/base_contract_interaction.ts

@@ -61,7 +61,7 @@ export abstract class BaseContractInteraction {
   public async prove(options: SendMethodOptions = {}): Promise<ProvenTx> {
     // docs:end:prove
     const txProvingResult = await this.proveInternal(options);
-    return new ProvenTx(this.wallet, txProvingResult.toTx(), txProvingResult.timings);
+    return new ProvenTx(this.wallet, txProvingResult.toTx(), txProvingResult.stats);
   }
 
   // docs:start:send

yarn-project/aztec.js/src/contract/contract_function_interaction.ts

@@ -2,7 +2,7 @@ import { ExecutionPayload } from '@aztec/entrypoints/payload';
 import { type FunctionAbi, FunctionSelector, FunctionType, decodeFromAbi, encodeArguments } from '@aztec/stdlib/abi';
 import type { AuthWitness } from '@aztec/stdlib/auth-witness';
 import { AztecAddress } from '@aztec/stdlib/aztec-address';
-import type { Capsule, HashedValues, SimulationTimings, TxExecutionRequest, TxProfileResult } from '@aztec/stdlib/tx';
+import type { Capsule, HashedValues, SimulationStats, TxExecutionRequest, TxProfileResult } from '@aztec/stdlib/tx';
 
 import type { Wallet } from '../wallet/wallet.js';
 import { BaseContractInteraction } from './base_contract_interaction.js';
@@ -16,20 +16,15 @@ import type {
 /**
  * Represents the result type of a simulation.
  * By default, it will just be the return value of the simulated function
- * so contract interfaces behave as plain functions. If `includeMetadata` is set to true,
+ * so contract interfaces behave as plain functions. If `includeStats` is set to true,
  * it will provide extra information.
  */
 type SimulationReturn<T extends boolean | undefined> = T extends true
   ? {
       /**
-       * Additional metadata about the simulation
+       * Additional stats about the simulation
        */
-      meta: {
-        /**
-         * Timings of the different operations performed, including per function breakdown
-         */
-        timings?: SimulationTimings;
-      };
+      stats: SimulationStats;
       /**
        * Return value of the function
        */
@@ -117,11 +112,9 @@ export class ContractFunctionInteraction extends BaseContractInteraction {
    * @param options - An optional object containing additional configuration for the transaction.
    * @returns The result of the transaction as returned by the contract function.
    */
-  public async simulate<T extends SimulateMethodOptions>(options?: T): Promise<SimulationReturn<T['includeMetadata']>>;
+  public async simulate<T extends SimulateMethodOptions>(options?: T): Promise<SimulationReturn<T['includeStats']>>;
   // eslint-disable-next-line jsdoc/require-jsdoc
-  public async simulate(
-    options: SimulateMethodOptions = {},
-  ): Promise<SimulationReturn<typeof options.includeMetadata>> {
+  public async simulate(options: SimulateMethodOptions = {}): Promise<SimulationReturn<typeof options.includeStats>> {
     // docs:end:simulate
     if (this.functionDao.functionType == FunctionType.UTILITY) {
       const utilityResult = await this.wallet.simulateUtility(
@@ -132,9 +125,9 @@ export class ContractFunctionInteraction extends BaseContractInteraction {
         options?.from,
       );
 
-      if (options.includeMetadata) {
+      if (options.includeStats) {
         return {
-          meta: { timings: utilityResult.timings },
+          stats: utilityResult.stats,
           result: utilityResult.result,
         };
       } else {
@@ -168,8 +161,8 @@ export class ContractFunctionInteraction extends BaseContractInteraction {
 
     const returnValue = rawReturnValues ? decodeFromAbi(this.functionDao.returnTypes, rawReturnValues) : [];
 
-    if (options.includeMetadata) {
-      return { meta: { timings: simulatedTx.timings }, result: returnValue };
+    if (options.includeStats) {
+      return { stats: simulatedTx.stats, result: returnValue };
     } else {
       return returnValue;
     }

yarn-project/aztec.js/src/contract/deploy_method.ts

@@ -250,7 +250,7 @@ export class DeployMethod<TContract extends ContractBase = Contract> extends Bas
       txProvingResult.toTx(),
       this.postDeployCtor,
       () => this.getInstance(options),
-      txProvingResult.timings,
+      txProvingResult.stats,
     );
   }
 

yarn-project/aztec.js/src/contract/deploy_proven_tx.ts

@@ -1,6 +1,6 @@
 import type { AztecAddress } from '@aztec/stdlib/aztec-address';
 import type { ContractInstanceWithAddress } from '@aztec/stdlib/contract';
-import type { ProvingTimings, Tx } from '@aztec/stdlib/tx';
+import type { ProvingStats, Tx } from '@aztec/stdlib/tx';
 
 import type { Wallet } from '../wallet/wallet.js';
 import type { Contract } from './contract.js';
@@ -16,9 +16,9 @@ export class DeployProvenTx<TContract extends Contract = Contract> extends Prove
     tx: Tx,
     private postDeployCtor: (address: AztecAddress, wallet: Wallet) => Promise<TContract>,
     private instanceGetter: () => Promise<ContractInstanceWithAddress>,
-    timings?: ProvingTimings,
+    stats?: ProvingStats,
   ) {
-    super(wallet, tx, timings);
+    super(wallet, tx, stats);
   }
 
   /**

yarn-project/aztec.js/src/contract/interaction_options.ts

@@ -42,8 +42,9 @@ export type SimulateMethodOptions = Pick<
   skipTxValidation?: boolean;
   /** Whether to ensure the fee payer is not empty and has enough balance to pay for the fee. */
   skipFeeEnforcement?: boolean;
-  /** Whether to include the metadata in the simulation result, instead of just the return of the function */
-  includeMetadata?: boolean;
+  /** Whether to include performance statistics (e.g. timing information of the different circuits and oracles) in
+   * the simulation result, instead of just the return value of the function */
+  includeStats?: boolean;
 };
 
 /**

yarn-project/aztec.js/src/contract/proven_tx.ts

@@ -1,4 +1,4 @@
-import { type ProvingTimings, Tx } from '@aztec/stdlib/tx';
+import { type ProvingStats, Tx } from '@aztec/stdlib/tx';
 
 import type { Wallet } from '../wallet/wallet.js';
 import { SentTx } from './sent_tx.js';
@@ -11,7 +11,7 @@ export class ProvenTx extends Tx {
     protected wallet: Wallet,
     tx: Tx,
     // eslint-disable-next-line jsdoc/require-jsdoc
-    public timings?: ProvingTimings,
+    public stats?: ProvingStats,
   ) {
     super(tx.data, tx.clientIvcProof, tx.contractClassLogs, tx.publicFunctionCalldata);
   }

yarn-project/cli-wallet/src/cmds/create_account.ts

@@ -108,7 +108,7 @@ export async function createAccount(
     } else {
       const provenTx = await deployMethod.prove({ ...deployOpts, universalDeploy: true, contractAddressSalt: salt });
       if (verbose) {
-        printProfileResult(provenTx.timings!, log);
+        printProfileResult(provenTx.stats!, log);
       }
       tx = provenTx.send();
 

yarn-project/cli-wallet/src/cmds/deploy.ts

@@ -64,7 +64,7 @@ export async function deploy(
 
   const provenTx = await deploy.prove(deployOpts);
   if (verbose) {
-    printProfileResult(provenTx.timings!, log);
+    printProfileResult(provenTx.stats!, log);
   }
 
   const tx = provenTx.send();

yarn-project/cli-wallet/src/cmds/deploy_account.ts

@@ -85,7 +85,7 @@ export async function deployAccount(
   } else {
     const provenTx = await deployMethod.prove({ ...deployOpts, universalDeploy: true, contractAddressSalt: salt });
     if (verbose) {
-      printProfileResult(provenTx.timings!, log);
+      printProfileResult(provenTx.stats!, log);
     }
     tx = provenTx.send();
 

yarn-project/cli-wallet/src/cmds/profile.ts

@@ -31,7 +31,7 @@ export async function profile(
     authWitnesses,
     skipProofGeneration: false,
   });
-  printProfileResult(result.timings, log, result.executionSteps);
+  printProfileResult(result.stats, log, result.executionSteps);
   if (debugOutputPath) {
     const ivcInputsPath = path.join(debugOutputPath, 'ivc-inputs.msgpack');
     log(`Debug output written to ${ivcInputsPath}.`);

yarn-project/cli-wallet/src/cmds/send.ts

@@ -50,7 +50,7 @@ export async function send(
 
   const provenTx = await call.prove(sendOptions);
   if (verbose) {
-    printProfileResult(provenTx.timings!, log);
+    printProfileResult(provenTx.stats!, log);
   }
 
   const tx = provenTx.send();

yarn-project/cli-wallet/src/cmds/simulate.ts

@@ -25,10 +25,10 @@ export async function simulate(
   const simulationResult = await call.simulate({
     ...(await feeOpts.toSendOpts(wallet)),
     authWitnesses,
-    includeMetadata: true,
+    includeStats: true,
   });
   if (verbose) {
-    printProfileResult(simulationResult.meta.timings!, log);
+    printProfileResult(simulationResult.stats!, log);
   }
   log(format('\nSimulation result: ', simulationResult.result, '\n'));
 }

yarn-project/cli-wallet/src/utils/profiling.ts

@@ -1,6 +1,6 @@
 import type { LogFn } from '@aztec/foundation/log';
 import type { PrivateExecutionStep } from '@aztec/stdlib/kernel';
-import type { ProvingTimings, SimulationTimings } from '@aztec/stdlib/tx';
+import type { ProvingStats, ProvingTimings, SimulationStats, SimulationTimings } from '@aztec/stdlib/tx';
 
 import { format } from 'util';
 
@@ -11,7 +11,7 @@ const COLUMN_MAX_WIDTH = 15;
 const ORACLE_NAME_PADDING = 50;
 
 export function printProfileResult(
-  timings: ProvingTimings | SimulationTimings,
+  stats: ProvingStats | SimulationStats,
   log: LogFn,
   executionSteps?: PrivateExecutionStep[],
 ) {
@@ -39,6 +39,7 @@ export function printProfileResult(
   let acc = 0;
   let biggest: PrivateExecutionStep | undefined = executionSteps?.[0];
 
+  const timings = stats.timings;
   timings.perFunction.forEach((fn, i) => {
     const currentExecutionStep = executionSteps?.[i];
     if (currentExecutionStep && biggest && currentExecutionStep.gateCount! > biggest.gateCount!) {
@@ -91,6 +92,27 @@ export function printProfileResult(
     );
   }
 
+  if (stats.nodeRPCCalls) {
+    log(format('\nRPC calls:\n'));
+    for (const [method, { times }] of Object.entries(stats.nodeRPCCalls)) {
+      const calls = times.length;
+      const total = times.reduce((acc, time) => acc + time, 0);
+      const avg = total / calls;
+      const min = Math.min(...times);
+      const max = Math.max(...times);
+      log(
+        format(
+          method.padEnd(ORACLE_NAME_PADDING),
+          `${calls} calls`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+          `${total.toFixed(2)}ms`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+          `min: ${min.toFixed(2)}ms`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+          `avg: ${avg.toFixed(2)}ms`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+          `max: ${max.toFixed(2)}ms`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+        ),
+      );
+    }
+  }
+
   log(format('\nSync time:'.padEnd(25), `${timings.sync?.toFixed(2)}ms`.padStart(16)));
   log(
     format(

yarn-project/end-to-end/src/bench/client_flows/benchmark.ts

@@ -7,7 +7,7 @@ import type {
 } from '@aztec/aztec.js';
 import { createLogger } from '@aztec/foundation/log';
 import { type PrivateExecutionStep, serializePrivateExecutionSteps } from '@aztec/stdlib/kernel';
-import type { ProvingTimings, SimulationTimings } from '@aztec/stdlib/tx';
+import type { ProvingStats, ProvingTimings, SimulationStats, SimulationTimings } from '@aztec/stdlib/tx';
 
 import assert from 'node:assert';
 import { mkdir, writeFile } from 'node:fs/promises';
@@ -94,24 +94,30 @@ export class ProxyLogger {
 
 export type ProverType = 'wasm' | 'native';
 
-type OracleRecording = {
+type CallRecording = {
+  // Number of times the function has been called
   calls: number;
+  // Maximum time taken by the function (in ms)
   max: number;
+  // Minimum time taken by the function (in ms)
   min: number;
+  // Average time taken by the function (in ms)
   avg: number;
+  // Total time spent in the function, computed as sum of all calls (in ms)
   total: number;
 };
 
 type Step = Pick<PrivateExecutionStep, 'functionName' | 'gateCount'> & {
   time: number;
   accGateCount?: number;
-  oracles: Record<string, OracleRecording>;
+  oracles: Record<string, CallRecording>;
 };
 
 type ClientFlowBenchmark = {
   name: string;
   timings: Omit<ProvingTimings & SimulationTimings, 'perFunction'> & { witgen: number };
   maxMemory: number;
+  rpc: Record<string, CallRecording>;
   proverType: ProverType;
   minimumTrace: StructuredTrace;
   totalGateCount: number;
@@ -158,7 +164,7 @@ function getMaxMemory(logs: Log[]): number {
 export function generateBenchmark(
   flow: string,
   logs: Log[],
-  timings: ProvingTimings | SimulationTimings,
+  stats: ProvingStats | SimulationStats,
   privateExecutionSteps: PrivateExecutionStep[],
   proverType: ProverType,
   error: string | undefined,
@@ -194,11 +200,12 @@ export function generateBenchmark(
             };
             return acc;
           },
-          {} as Record<string, OracleRecording>,
+          {} as Record<string, CallRecording>,
         ),
       },
     ];
   }, []);
+  const timings = stats.timings;
   const totalGateCount = steps[steps.length - 1].accGateCount;
   return {
     name: flow,
@@ -209,6 +216,21 @@ export function generateBenchmark(
       unaccounted: timings.unaccounted,
       witgen: timings.perFunction.reduce((acc, fn) => acc + fn.time, 0),
     },
+    rpc: Object.entries(stats.nodeRPCCalls ?? {}).reduce(
+      (acc, [RPCName, RPCCalls]) => {
+        const total = RPCCalls.times.reduce((sum, time) => sum + time, 0);
+        const calls = RPCCalls.times.length;
+        acc[RPCName] = {
+          calls,
+          max: Math.max(...RPCCalls.times),
+          min: Math.min(...RPCCalls.times),
+          total,
+          avg: total / calls,
+        };
+        return acc;
+      },
+      {} as Record<string, CallRecording>,
+    ),
     maxMemory,
     proverType,
     minimumTrace: minimumTrace!,
@@ -219,6 +241,7 @@ export function generateBenchmark(
 }
 
 export function convertProfileToGHBenchmark(benchmark: ClientFlowBenchmark): GithubActionBenchmarkResult[] {
+  const totalRPCCalls = Object.values(benchmark.rpc).reduce((acc, call) => acc + call.calls, 0);
   const benches = [
     {
       name: `${benchmark.name}/witgen`,
@@ -247,6 +270,11 @@ export function convertProfileToGHBenchmark(benchmark: ClientFlowBenchmark): Git
       value: benchmark.totalGateCount,
       unit: 'gates',
     },
+    {
+      name: `${benchmark.name}/rpc`,
+      value: totalRPCCalls,
+      unit: 'calls',
+    },
   ];
   if (benchmark.timings.proving) {
     benches.push({
@@ -278,7 +306,7 @@ export async function captureProfile(
   if (expectedSteps !== undefined && result.executionSteps.length !== expectedSteps) {
     throw new Error(`Expected ${expectedSteps} execution steps, got ${result.executionSteps.length}`);
   }
-  const benchmark = generateBenchmark(label, logs, result.timings, result.executionSteps, 'wasm', undefined);
+  const benchmark = generateBenchmark(label, logs, result.stats, result.executionSteps, 'wasm', undefined);
 
   const ivcFolder = process.env.CAPTURE_IVC_FOLDER;
   if (ivcFolder) {