feat: measure oracles

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

@@ -2,6 +2,8 @@ import { type AccountWalletWithSecretKey, type AztecAddress, Contract } from '@a
 import { prepTx } from '@aztec/cli/utils';
 import type { LogFn } from '@aztec/foundation/log';
 
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
+
 export async function authorizeAction(
   wallet: AccountWalletWithSecretKey,
   functionName: string,
@@ -28,7 +30,7 @@ export async function authorizeAction(
   const action = contract.methods[functionName](...functionArgs);
 
   const setAuthwitnessInteraction = await wallet.setPublicAuthWit({ caller, action }, true);
-  const witness = await setAuthwitnessInteraction.send().wait();
+  const witness = await setAuthwitnessInteraction.send().wait({ timeout: DEFAULT_TX_TIMEOUT });
 
   log(`Authorized action ${functionName} on contract ${contractAddress} for caller ${caller}`);
 

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

@@ -5,6 +5,8 @@ import { Fr } from '@aztec/foundation/fields';
 import type { LogFn } from '@aztec/foundation/log';
 import { GasFees, GasSettings } from '@aztec/stdlib/gas';
 
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
+
 export async function cancelTx(
   wallet: AccountWalletWithSecretKey,
   {
@@ -46,7 +48,7 @@ export async function cancelTx(
   const txProvingResult = await wallet.proveTx(txRequest, txSimulationResult.privateExecutionResult);
   const sentTx = new SentTx(wallet, wallet.sendTx(txProvingResult.toTx()));
   try {
-    await sentTx.wait();
+    await sentTx.wait({ timeout: DEFAULT_TX_TIMEOUT });
 
     log('Transaction has been cancelled');
 

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

@@ -6,6 +6,7 @@ import type { LogFn, Logger } from '@aztec/foundation/log';
 import { type AccountType, createOrRetrieveAccount } from '../utils/accounts.js';
 import { type IFeeOpts, printGasEstimates } from '../utils/options/fees.js';
 import { printProfileResult } from '../utils/profiling.js';
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
 
 export async function createAccount(
   client: PXE,
@@ -118,7 +119,7 @@ export async function createAccount(
         if (!json) {
           log(`\nWaiting for account contract deployment...`);
         }
-        txReceipt = await tx.wait();
+        txReceipt = await tx.wait({ timeout: DEFAULT_TX_TIMEOUT });
         out.txReceipt = {
           status: txReceipt.status,
           transactionFee: txReceipt.transactionFee,

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

@@ -6,6 +6,7 @@ import { PublicKeys } from '@aztec/stdlib/keys';
 
 import { type IFeeOpts, printGasEstimates } from '../utils/options/fees.js';
 import { printProfileResult } from '../utils/profiling.js';
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
 
 export async function deploy(
   wallet: AccountWalletWithSecretKey,
@@ -71,7 +72,7 @@ export async function deploy(
   const txHash = await tx.getTxHash();
   debugLogger.debug(`Deploy tx sent with hash ${txHash}`);
   if (wait) {
-    const deployed = await tx.wait();
+    const deployed = await tx.wait({ timeout: DEFAULT_TX_TIMEOUT });
     const { address, partialAddress, instance } = deployed.contract;
     if (json) {
       logJson({

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

@@ -4,6 +4,7 @@ import type { LogFn, Logger } from '@aztec/foundation/log';
 
 import { type IFeeOpts, printGasEstimates } from '../utils/options/fees.js';
 import { printProfileResult } from '../utils/profiling.js';
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
 
 export async function deployAccount(
   account: AccountManager,
@@ -95,7 +96,7 @@ export async function deployAccount(
       if (!json) {
         log(`\nWaiting for account contract deployment...`);
       }
-      txReceipt = await tx.wait();
+      txReceipt = await tx.wait({ timeout: DEFAULT_TX_TIMEOUT });
       out.txReceipt = {
         status: txReceipt.status,
         transactionFee: txReceipt.transactionFee,

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

@@ -12,6 +12,7 @@ import { GasSettings } from '@aztec/stdlib/gas';
 
 import { type IFeeOpts, printGasEstimates } from '../utils/options/fees.js';
 import { printProfileResult } from '../utils/profiling.js';
+import { DEFAULT_TX_TIMEOUT } from '../utils/pxe_wrapper.js';
 
 export async function send(
   wallet: AccountWalletWithSecretKey,
@@ -57,7 +58,7 @@ export async function send(
   log(`\nTransaction hash: ${txHash.toString()}`);
   if (wait) {
     try {
-      await tx.wait();
+      await tx.wait({ timeout: DEFAULT_TX_TIMEOUT });
 
       log('Transaction has been mined');
 

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

@@ -4,6 +4,12 @@ import type { ProvingTimings, SimulationTimings } from '@aztec/stdlib/tx';
 
 import { format } from 'util';
 
+const FN_NAME_PADDING = 50;
+const COLUMN_MIN_WIDTH = 13;
+const COLUMN_MAX_WIDTH = 15;
+
+const ORACLE_NAME_PADDING = 50;
+
 export function printProfileResult(
   timings: ProvingTimings | SimulationTimings,
   log: LogFn,
@@ -13,13 +19,23 @@ export function printProfileResult(
   log(
     format(
       '  ',
-      'Function name'.padEnd(50),
-      'Time'.padStart(13).padEnd(15),
-      executionSteps ? 'Gates'.padStart(13).padEnd(15) : '',
-      executionSteps ? 'Subtotal'.padStart(13).padEnd(15) : '',
+      'Function name'.padEnd(FN_NAME_PADDING),
+      'Time'.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+      executionSteps ? 'Gates'.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH) : '',
+      executionSteps ? 'Subtotal'.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH) : '',
+    ),
+  );
+  log(
+    format(
+      ''.padEnd(
+        FN_NAME_PADDING +
+          COLUMN_MAX_WIDTH +
+          COLUMN_MAX_WIDTH +
+          (executionSteps ? COLUMN_MAX_WIDTH + COLUMN_MAX_WIDTH : 0),
+        '-',
+      ),
     ),
   );
-  log(format(''.padEnd(50 + 15 + 15 + (executionSteps ? 15 + 15 : 0), '-')));
   let acc = 0;
   let biggest: PrivateExecutionStep | undefined = executionSteps?.[0];
 
@@ -32,13 +48,37 @@ export function printProfileResult(
 
     log(
       format(
-        '  ',
-        fn.functionName.padEnd(50),
-        `${fn.time.toFixed(2)}ms`.padStart(13).padEnd(15),
-        currentExecutionStep ? currentExecutionStep.gateCount!.toLocaleString().padStart(13).padEnd(15) : '',
-        currentExecutionStep ? acc.toLocaleString().padStart(15) : '',
+        ' - ',
+        fn.functionName.padEnd(FN_NAME_PADDING),
+        `${fn.time.toFixed(2)}ms`.padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH),
+        currentExecutionStep
+          ? currentExecutionStep.gateCount!.toLocaleString().padStart(COLUMN_MIN_WIDTH).padEnd(COLUMN_MAX_WIDTH)
+          : '',
+        currentExecutionStep ? acc.toLocaleString().padStart(COLUMN_MAX_WIDTH) : '',
       ),
     );
+    if (fn.oracles) {
+      log('');
+      for (const [oracleName, { times }] of Object.entries(fn.oracles)) {
+        const calls = times.length;
+        const min = Math.min(...times);
+        const max = Math.max(...times);
+        const total = times.reduce((acc, time) => acc + time, 0);
+        const avg = total / calls;
+        log(
+          format(
+            '    ',
+            oracleName.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('');
   });
 
   if (biggest) {
@@ -55,31 +95,39 @@ export function printProfileResult(
   log(
     format(
       'Private simulation time:'.padEnd(25),
-      `${timings.perFunction.reduce((acc, { time }) => acc + time, 0).toFixed(2)}ms`.padStart(15),
+      `${timings.perFunction.reduce((acc, { time }) => acc + time, 0).toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
     ),
   );
   if ((timings as ProvingTimings).proving) {
-    log(format('Proving time:'.padEnd(25), `${(timings as ProvingTimings).proving?.toFixed(2)}ms`.padStart(15)));
+    log(
+      format(
+        'Proving time:'.padEnd(25),
+        `${(timings as ProvingTimings).proving?.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
+      ),
+    );
   }
   if ((timings as SimulationTimings).publicSimulation) {
     log(
       format(
         'Public simulation time:'.padEnd(25),
-        `${(timings as SimulationTimings).publicSimulation?.toFixed(2)}ms`.padStart(15),
+        `${(timings as SimulationTimings).publicSimulation?.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
       ),
     );
   }
 
   if ((timings as SimulationTimings).validation) {
     log(
-      format('Validation time:'.padEnd(25), `${(timings as SimulationTimings).validation?.toFixed(2)}ms`.padStart(15)),
+      format(
+        'Validation time:'.padEnd(25),
+        `${(timings as SimulationTimings).validation?.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
+      ),
     );
   }
 
   log(
     format(
       'Total time:'.padEnd(25),
-      `${timings.total.toFixed(2)}ms`.padStart(15),
+      `${timings.total.toFixed(2)}ms`.padStart(COLUMN_MAX_WIDTH),
       `(${timings.unaccounted.toFixed(2)}ms unaccounted)`,
     ),
   );

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

@@ -1,6 +1,8 @@
 import { type PXEServiceConfig, createPXEService, getPXEServiceConfig } from '@aztec/pxe/server';
 import { type AztecNode, type PXE, createAztecNodeClient } from '@aztec/stdlib/interfaces/client';
 
+export const DEFAULT_TX_TIMEOUT = 180;
+
 /*
  * Wrapper class for PXE service, avoids initialization issues due to
  * closures when providing PXE service to injected commander.js commands

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

@@ -94,7 +94,19 @@ export class ProxyLogger {
 
 export type ProverType = 'wasm' | 'native';
 
-type Step = Pick<PrivateExecutionStep, 'functionName' | 'gateCount'> & { time: number; accGateCount?: number };
+type OracleRecording = {
+  calls: number;
+  max: number;
+  min: number;
+  avg: number;
+  total: number;
+};
+
+type Step = Pick<PrivateExecutionStep, 'functionName' | 'gateCount'> & {
+  time: number;
+  accGateCount?: number;
+  oracles: Record<string, OracleRecording>;
+};
 
 type ClientFlowBenchmark = {
   name: string;
@@ -169,6 +181,21 @@ export function generateBenchmark(
         gateCount: step.gateCount,
         accGateCount: previousAccGateCount + step.gateCount!,
         time: step.timings.witgen,
+        oracles: Object.entries(step.timings.oracles ?? {}).reduce(
+          (acc, [oracleName, oracleData]) => {
+            const total = oracleData.times.reduce((sum, time) => sum + time, 0);
+            const calls = oracleData.times.length;
+            acc[oracleName] = {
+              calls,
+              max: Math.max(...oracleData.times),
+              min: Math.min(...oracleData.times),
+              total,
+              avg: total / calls,
+            };
+            return acc;
+          },
+          {} as Record<string, OracleRecording>,
+        ),
       },
     ];
   }, []);

yarn-project/end-to-end/src/fixtures/utils.ts

@@ -59,8 +59,8 @@ import {
 } from '@aztec/pxe/server';
 import type { SequencerClient } from '@aztec/sequencer-client';
 import type { TestSequencerClient } from '@aztec/sequencer-client/test';
-import { WASMSimulator } from '@aztec/simulator/client';
-import { SimulationProviderRecorderWrapper } from '@aztec/simulator/testing';
+import { MemoryCircuitRecorder, SimulationProviderRecorderWrapper, WASMSimulator } from '@aztec/simulator/client';
+import { FileCircuitRecorder } from '@aztec/simulator/testing';
 import { getContractClassFromArtifact, getContractInstanceFromDeployParams } from '@aztec/stdlib/contract';
 import type { AztecNodeAdmin } from '@aztec/stdlib/interfaces/client';
 import type { PublicDataTreeLeaf } from '@aztec/stdlib/trees';
@@ -171,7 +171,10 @@ export async function setupPXEService(
   }
 
   const simulationProvider = new WASMSimulator();
-  const simulationProviderWithRecorder = new SimulationProviderRecorderWrapper(simulationProvider);
+  const recorder = process.env.CIRCUIT_RECORD_DIR
+    ? new FileCircuitRecorder(process.env.CIRCUIT_RECORD_DIR)
+    : new MemoryCircuitRecorder();
+  const simulationProviderWithRecorder = new SimulationProviderRecorderWrapper(simulationProvider, recorder);
   const pxe = await createPXEServiceWithSimulationProvider(
     aztecNode,
     simulationProviderWithRecorder,

yarn-project/pxe/src/entrypoints/server/utils.ts

@@ -3,8 +3,13 @@ import { BBWASMBundlePrivateKernelProver } from '@aztec/bb-prover/client/wasm/bu
 import { randomBytes } from '@aztec/foundation/crypto';
 import { type Logger, createLogger } from '@aztec/foundation/log';
 import { BundledProtocolContractsProvider } from '@aztec/protocol-contracts/providers/bundle';
-import { type SimulationProvider, WASMSimulator } from '@aztec/simulator/client';
-import { SimulationProviderRecorderWrapper } from '@aztec/simulator/testing';
+import {
+  MemoryCircuitRecorder,
+  type SimulationProvider,
+  SimulationProviderRecorderWrapper,
+  WASMSimulator,
+} from '@aztec/simulator/client';
+import { FileCircuitRecorder } from '@aztec/simulator/testing';
 import type { AztecNode } from '@aztec/stdlib/interfaces/client';
 
 import type { PXEServiceConfig } from '../../config/index.js';
@@ -26,7 +31,10 @@ export function createPXEService(
   options: PXECreationOptions = { loggers: {} },
 ) {
   const simulationProvider = new WASMSimulator();
-  const simulationProviderWithRecorder = new SimulationProviderRecorderWrapper(simulationProvider);
+  const recorder = process.env.CIRCUIT_RECORD_DIR
+    ? new FileCircuitRecorder(process.env.CIRCUIT_RECORD_DIR)
+    : new MemoryCircuitRecorder();
+  const simulationProviderWithRecorder = new SimulationProviderRecorderWrapper(simulationProvider, recorder);
   return createPXEServiceWithSimulationProvider(aztecNode, simulationProviderWithRecorder, config, options);
 }
 

yarn-project/pxe/src/private_kernel/private_kernel_execution_prover.ts

@@ -154,6 +154,7 @@ export class PrivateKernelExecutionProver {
         vk: currentExecution.vk,
         timings: {
           witgen: currentExecution.profileResult?.timings.witgen ?? 0,
+          oracles: currentExecution.profileResult?.timings.oracles,
         },
       });
 

yarn-project/pxe/src/pxe_service/pxe_service.ts

@@ -679,9 +679,10 @@ export class PXEService implements PXE {
 
         const totalTime = totalTimer.ms();
 
-        const perFunction = executionSteps.map(({ functionName, timings: { witgen } }) => ({
+        const perFunction = executionSteps.map(({ functionName, timings: { witgen, oracles } }) => ({
           functionName,
           time: witgen,
+          oracles,
         }));
 
         const timings: ProvingTimings = {
@@ -746,10 +747,13 @@ export class PXEService implements PXE {
 
         const totalTime = totalTimer.ms();
 
-        const perFunction = executionSteps.map(({ functionName, timings: { witgen } }) => ({
-          functionName,
-          time: witgen,
-        }));
+        const perFunction = executionSteps.map(({ functionName, timings: { witgen, oracles } }) => {
+          return {
+            functionName,
+            time: witgen,
+            oracles,
+          };
+        });
 
         // Gate computation is time is not relevant for profiling, so we subtract it from the total time.
         const gateCountComputationTime =
@@ -849,9 +853,10 @@ export class PXEService implements PXE {
 
         const totalTime = totalTimer.ms();
 
-        const perFunction = executionSteps.map(({ functionName, timings: { witgen } }) => ({
+        const perFunction = executionSteps.map(({ functionName, timings: { witgen, oracles } }) => ({
           functionName,
           time: witgen,
+          oracles,
         }));
 
         const timings: SimulationTimings = {

yarn-project/simulator/src/client.ts

@@ -1,4 +1,6 @@
 export * from './private/index.js';
 export { WASMSimulator } from './private/providers/acvm_wasm.js';
+export { SimulationProviderRecorderWrapper } from './private/providers/circuit_recording/simulation_provider_recorder_wrapper.js';
+export { MemoryCircuitRecorder } from './private/providers/circuit_recording/memory_circuit_recorder.js';
 export { type SimulationProvider, type DecodedError } from './private/providers/simulation_provider.js';
 export * from './common/index.js';