chore: Measure circuit simulation times and input/output sizes (#2663)

Tracks running time for all circuit simulation calls, as well as the
serialised size of their inputs and outputs.

Also introduces a new contract specific for benchmarking, so it
exercises all code paths we need, and it remains unchanged as much as
possible so we don't alter the benchmark results due to changes to the
contract being tested.

scripts/ci/aggregate_e2e_benchmark.js

@@ -2,6 +2,12 @@
 // output with the grouped metrics to be published. This script can probably
 // be replaced by a single call to jq, but I found this easier to write,
 // and pretty much every CI comes with a working version of node.
+//
+// To test this locally, first run the benchmark tests from the yarn-project/end-to-end folder
+// BENCHMARK=1 ROLLUP_SIZES=8 yarn test bench
+//
+// And then run this script from the root of the project:
+// LOGS_DIR=./yarn-project/end-to-end/log/ node ./scripts/ci/aggregate_e2e_benchmark.js 
 
 const fs = require("fs");
 const path = require("path");
@@ -14,6 +20,10 @@ const {
   L2_BLOCK_PROCESSING_TIME,
   L2_BLOCK_SYNCED,
   L2_BLOCK_PUBLISHED_TO_L1,
+  CIRCUIT_SIMULATION_TIME,
+  CIRCUIT_OUTPUT_SIZE,
+  CIRCUIT_INPUT_SIZE,
+  CIRCUIT_SIMULATED,
   ROLLUP_SIZES,
   BENCHMARK_FILE_JSON,
 } = require("./benchmark_shared.js");
@@ -55,13 +65,25 @@ function processRollupBlockSynced(entry, results) {
   append(results, L2_BLOCK_PROCESSING_TIME, bucket, entry.duration);
 }
 
+// Processes an entry with event name 'circuit-simulated' and updates results
+// Buckets are circuit names
+function processCircuitSimulation(entry, results) {
+  const bucket = entry.circuitName;
+  if (!bucket) return;
+  append(results, CIRCUIT_SIMULATION_TIME, bucket, entry.duration);
+  append(results, CIRCUIT_INPUT_SIZE, bucket, entry.inputSize);
+  append(results, CIRCUIT_OUTPUT_SIZE, bucket, entry.outputSize);
+}
+
 // Processes a parsed entry from a logfile and updates results
 function processEntry(entry, results) {
   switch (entry.eventName) {
     case L2_BLOCK_PUBLISHED_TO_L1:
       return processRollupPublished(entry, results);
     case L2_BLOCK_SYNCED:
       return processRollupBlockSynced(entry, results);
+    case CIRCUIT_SIMULATED:
+      return processCircuitSimulation(entry, results);
     default:
       return;
   }

scripts/ci/benchmark_shared.js

@@ -1,13 +1,3 @@
-// Metrics to capture
-const L1_ROLLUP_CALLDATA_SIZE_IN_BYTES = "l1_rollup_calldata_size_in_bytes";
-const L1_ROLLUP_CALLDATA_GAS = "l1_rollup_calldata_gas";
-const L1_ROLLUP_EXECUTION_GAS = "l1_rollup_execution_gas";
-const L2_BLOCK_PROCESSING_TIME = "l2_block_processing_time_in_ms";
-
-// Events to track
-const L2_BLOCK_PUBLISHED_TO_L1 = "rollup-published-to-l1";
-const L2_BLOCK_SYNCED = "l2-block-handled";
-
 // Rollup sizes to track (duplicated from yarn-project/end-to-end/src/benchmarks/bench_publish_rollup.test.ts)
 const ROLLUP_SIZES = process.env.ROLLUP_SIZES
   ? process.env.ROLLUP_SIZES.split(",").map(Number)
@@ -17,12 +7,19 @@ const ROLLUP_SIZES = process.env.ROLLUP_SIZES
 const BENCHMARK_FILE_JSON = process.env.BENCHMARK_FILE_JSON ?? "benchmark.json";
 
 module.exports = {
-  L1_ROLLUP_CALLDATA_SIZE_IN_BYTES,
-  L1_ROLLUP_CALLDATA_GAS,
-  L1_ROLLUP_EXECUTION_GAS,
-  L2_BLOCK_PROCESSING_TIME,
-  L2_BLOCK_PUBLISHED_TO_L1,
-  L2_BLOCK_SYNCED,
+  // Metrics to capture
+  L1_ROLLUP_CALLDATA_SIZE_IN_BYTES: "l1_rollup_calldata_size_in_bytes",
+  L1_ROLLUP_CALLDATA_GAS: "l1_rollup_calldata_gas",
+  L1_ROLLUP_EXECUTION_GAS: "l1_rollup_execution_gas",
+  L2_BLOCK_PROCESSING_TIME: "l2_block_processing_time_in_ms",
+  CIRCUIT_SIMULATION_TIME: "circuit_simulation_time_in_ms",
+  CIRCUIT_INPUT_SIZE: "circuit_input_size_in_bytes",
+  CIRCUIT_OUTPUT_SIZE: "circuit_output_size_in_bytes",
+  // Events to track
+  L2_BLOCK_PUBLISHED_TO_L1: "rollup-published-to-l1",
+  L2_BLOCK_SYNCED: "l2-block-handled",
+  CIRCUIT_SIMULATED: "circuit-simulation",
+  // Other
   ROLLUP_SIZES,
   BENCHMARK_FILE_JSON,
 };

yarn-project/end-to-end/src/benchmarks/bench_publish_rollup.test.ts

@@ -1,8 +1,8 @@
 /* eslint-disable camelcase */
 import { AztecNodeService } from '@aztec/aztec-node';
-import { AztecAddress } from '@aztec/aztec.js';
+import { AztecAddress, BatchCall } from '@aztec/aztec.js';
 import { sleep } from '@aztec/foundation/sleep';
-import { TokenContract } from '@aztec/noir-contracts/types';
+import { BenchmarkingContract } from '@aztec/noir-contracts/types';
 import { SequencerClient } from '@aztec/sequencer-client';
 
 import times from 'lodash.times';
@@ -13,29 +13,33 @@ const ROLLUP_SIZES = process.env.ROLLUP_SIZES ? process.env.ROLLUP_SIZES.split('
 
 describe('benchmarks/publish_rollup', () => {
   let context: Awaited<ReturnType<typeof setup>>;
-  let token: TokenContract;
+  let contract: BenchmarkingContract;
   let owner: AztecAddress;
-  let recipient: AztecAddress;
   let sequencer: SequencerClient;
 
   beforeEach(async () => {
     context = await setup(2, { maxTxsPerBlock: 1024 });
-
-    if (!(context.aztecNode instanceof AztecNodeService)) throw new Error('Aztec node is not a service');
-    sequencer = context.aztecNode!.getSequencer()!;
-
-    [owner, recipient] = context.accounts.map(a => a.address);
-    token = await TokenContract.deploy(context.wallet, owner).send().deployed();
-    await token.methods.mint_public(owner, 10000n).send().wait();
+    [owner] = context.accounts.map(a => a.address);
+    contract = await BenchmarkingContract.deploy(context.wallet).send().deployed();
+    sequencer = (context.aztecNode as AztecNodeService).getSequencer()!;
     await sequencer.stop();
   }, 60_000);
 
+  const makeBatchCall = (i: number) =>
+    new BatchCall(context.wallet, [
+      contract.methods.create_note(owner, i).request(),
+      contract.methods.increment_balance(owner, i).request(),
+    ]);
+
   it.each(ROLLUP_SIZES)(
     `publishes a rollup with %d txs`,
     async (txCount: number) => {
       context.logger(`Assembling rollup with ${txCount} txs`);
-      // Simulate and simultaneously send ROLLUP_SIZE txs. These should not yet be processed since sequencer is stopped.
-      const calls = times(txCount, () => token.methods.transfer_public(owner, recipient, 1, 0));
+      // Simulate and simultaneously send %d txs. These should not yet be processed since sequencer is stopped.
+      // Each tx has a private execution (account entrypoint), a nested private call (create_note),
+      // a public call (increment_balance), and a nested public call (broadcast). These include
+      // emitting one private note and one unencrypted log, two storage reads and one write.
+      const calls = times(txCount, makeBatchCall);
       calls.forEach(call => call.simulate({ skipPublicSimulation: true }));
       const sentTxs = calls.map(call => call.send());
 

yarn-project/end-to-end/src/cli_docs_sandbox.test.ts

@@ -94,6 +94,7 @@ Rollup Address: 0x0dcd1bf9a1b36ce34237eeafef220932846bcd82
     const docs = `
 // docs:start:example-contracts
 % aztec-cli example-contracts
+BenchmarkingContractAbi
 CardGameContractAbi
 ChildContractAbi
 DocsExampleContractAbi

yarn-project/end-to-end/src/integration_l1_publisher.test.ts

@@ -126,7 +126,7 @@ describe('L1Publisher integration', () => {
 
     builderDb = await MerkleTrees.new(levelup((memdown as any)())).then(t => t.asLatest());
     const vks = getVerificationKeys();
-    const simulator = await WasmRollupCircuitSimulator.new();
+    const simulator = new WasmRollupCircuitSimulator();
     const prover = new EmptyRollupProver();
     builder = new SoloBlockBuilder(builderDb, vks, simulator, prover);
 

yarn-project/foundation/src/timer/elapsed.ts

@@ -3,10 +3,21 @@ import { Timer } from './timer.js';
 /**
  * Measures the elapsed execution time of a function call or promise once it is awaited.
  * @param fn - Function or promise.
- * @returns A timer object.
+ * @returns A timer object and the result.
  */
 export async function elapsed<T>(fn: Promise<T> | (() => T | Promise<T>)): Promise<[Timer, T]> {
   const timer = new Timer();
   const result = await (typeof fn === 'function' ? fn() : fn);
   return [timer, result];
 }
+
+/**
+ * Measures the elapsed execution time of a synchronous function call once it is awaited.
+ * @param fn - Function.
+ * @returns A timer object and the result.
+ */
+export function elapsedSync<T>(fn: () => T): [Timer, T] {
+  const timer = new Timer();
+  const result = fn();
+  return [timer, result];
+}

yarn-project/foundation/src/timer/index.ts

@@ -1,3 +1,3 @@
 export { TimeoutTask } from './timeout.js';
 export { Timer } from './timer.js';
-export { elapsed } from './elapsed.js';
+export { elapsed, elapsedSync } from './elapsed.js';

yarn-project/noir-contracts/Nargo.toml

@@ -1,5 +1,6 @@
 [workspace]
 members = [
+    "src/contracts/benchmarking_contract", 
     "src/contracts/card_game_contract", 
     "src/contracts/child_contract", 
     "src/contracts/docs_example_contract",

yarn-project/noir-contracts/src/contracts/benchmarking_contract/Nargo.toml

@@ -0,0 +1,9 @@
+[package]
+name = "benchmarking_contract"
+authors = [""]
+compiler_version = "0.1"
+type = "contract"
+
+[dependencies]
+aztec = { path = "../../../../aztec-nr/aztec" }
+value_note = { path = "../../../../aztec-nr/value-note" }

yarn-project/noir-contracts/src/contracts/benchmarking_contract/src/main.nr

@@ -0,0 +1,74 @@
+// A contract used for running benchmarks.
+// We should try to change this contract as little as possible, since any modification
+// would alter the metrics we're capturing in the benchmarks, and we want to keep the
+// subject being tested as unmodified as possible so we can detect metric changes that 
+// arise from code changes.
+
+contract Benchmarking {
+    use dep::value_note::{
+        utils::{increment, decrement},
+        value_note::{VALUE_NOTE_LEN, ValueNote, ValueNoteMethods},
+    };
+
+    use dep::aztec::{
+        context::{Context},
+        note::note_getter_options::NoteGetterOptions,
+        oracle::compute_selector::compute_selector,
+        log::emit_unencrypted_log,
+        state_vars::{map::Map, public_state::PublicState, set::Set},
+        types::type_serialization::field_serialization::{FieldSerializationMethods, FIELD_SERIALIZED_LEN},
+        types::address::{AztecAddress},
+    };
+
+    struct Storage {
+        notes: Map<Set<ValueNote, VALUE_NOTE_LEN>>,
+        balances: Map<PublicState<Field, FIELD_SERIALIZED_LEN>>,
+    }
+
+    impl Storage {
+        fn init(context: Context) -> pub Self {
+            Storage {
+                notes: Map::new(context, 1, |context, slot| { Set::new(context, slot, ValueNoteMethods) }),
+                balances: Map::new(context, 2, |context, slot| { PublicState::new(context, slot, FieldSerializationMethods) }),
+            }
+        }
+    }
+
+    #[aztec(private)]
+    fn constructor() {}
+
+    // Creates a new value note for the target owner. Use this method to seed an initial set of notes.
+    #[aztec(private)]
+    fn create_note(owner: Field, value: Field) {
+        increment(storage.notes.at(owner), value, owner);
+    }
+
+    // Deletes a note at a specific index in the set and creates a new one with the same value.
+    // We explicitly pass in the note index so we can ensure we consume different notes when sending
+    // multiple txs that will land on the same block.
+    // See https://discourse.aztec.network/t/utxo-concurrency-issues-for-private-state/635
+    // by @rahul-kothari for a full explanation on why this is needed.
+    #[aztec(private)]
+    fn recreate_note(owner: Field, index: u32) {
+        let owner_notes = storage.notes.at(owner); 
+        let getter_options = NoteGetterOptions::new().set_limit(1).set_offset(index);
+        let notes = owner_notes.get_notes(getter_options);
+        let note = notes[0].unwrap_unchecked();
+        owner_notes.remove(note);
+        increment(owner_notes, note.value, owner);
+    }
+
+    // Reads and writes to public storage and enqueues a call to another public function.
+    #[aztec(public)]
+    fn increment_balance(owner: Field, value: Field) {
+        let current = storage.balances.at(owner).read();
+        storage.balances.at(owner).write(current + value);
+        let _callStackItem1 = context.call_public_function(context.this_address(), compute_selector("broadcast(Field)"), [owner]);        
+    }
+
+    // Emits a public log.
+    #[aztec(public)]
+    fn broadcast(owner: Field) {
+        emit_unencrypted_log(&mut context, storage.balances.at(owner).read());
+    }
+}

yarn-project/pxe/src/kernel_prover/proof_creator.ts

@@ -16,6 +16,7 @@ import {
 import { siloCommitment } from '@aztec/circuits.js/abis';
 import { Fr } from '@aztec/foundation/fields';
 import { createDebugLogger } from '@aztec/foundation/log';
+import { elapsed } from '@aztec/foundation/timer';
 
 /**
  * Represents the output of the proof creation process for init and inner private kernel circuit.
@@ -108,15 +109,19 @@ export class KernelProofCreator implements ProofCreator {
 
   public async createProofInit(privateInputs: PrivateKernelInputsInit): Promise<ProofOutput> {
     const wasm = await CircuitsWasm.get();
-    this.log('Executing private kernel simulation init...');
-    const result = privateKernelSimInit(wasm, privateInputs);
+    const [time, result] = await elapsed(() => privateKernelSimInit(wasm, privateInputs));
     if (result instanceof CircuitError) {
       throw new CircuitError(result.code, result.message);
     }
+    this.log(`Simulated private kernel init`, {
+      eventName: 'circuit-simulation',
+      circuitName: 'private-kernel-init',
+      duration: time.ms(),
+      inputSize: privateInputs.toBuffer().length,
+      outputSize: result.toBuffer().length,
+    });
     this.log('Skipping private kernel init proving...');
-    // TODO
     const proof = makeEmptyProof();
-    this.log('Kernel Prover Init Completed!');
 
     return {
       publicInputs: result,
@@ -126,15 +131,19 @@ export class KernelProofCreator implements ProofCreator {
 
   public async createProofInner(privateInputs: PrivateKernelInputsInner): Promise<ProofOutput> {
     const wasm = await CircuitsWasm.get();
-    this.log('Executing private kernel simulation inner...');
-    const result = privateKernelSimInner(wasm, privateInputs);
+    const [time, result] = await elapsed(() => privateKernelSimInner(wasm, privateInputs));
     if (result instanceof CircuitError) {
       throw new CircuitError(result.code, result.message);
     }
+    this.log(`Simulated private kernel inner`, {
+      eventName: 'circuit-simulation',
+      circuitName: 'private-kernel-inner',
+      duration: time.ms(),
+      inputSize: privateInputs.toBuffer().length,
+      outputSize: result.toBuffer().length,
+    });
     this.log('Skipping private kernel inner proving...');
-    // TODO
     const proof = makeEmptyProof();
-    this.log('Kernel Prover Inner Completed!');
 
     return {
       publicInputs: result,
@@ -145,14 +154,19 @@ export class KernelProofCreator implements ProofCreator {
   public async createProofOrdering(privateInputs: PrivateKernelInputsOrdering): Promise<ProofOutputFinal> {
     const wasm = await CircuitsWasm.get();
     this.log('Executing private kernel simulation ordering...');
-    const result = privateKernelSimOrdering(wasm, privateInputs);
+    const [time, result] = await elapsed(() => privateKernelSimOrdering(wasm, privateInputs));
     if (result instanceof CircuitError) {
       throw new CircuitError(result.code, result.message);
     }
+    this.log(`Simulated private kernel ordering`, {
+      eventName: 'circuit-simulation',
+      circuitName: 'private-kernel-ordering',
+      duration: time.ms(),
+      inputSize: privateInputs.toBuffer().length,
+      outputSize: result.toBuffer().length,
+    });
     this.log('Skipping private kernel ordering proving...');
-    // TODO
     const proof = makeEmptyProof();
-    this.log('Ordering Kernel Prover Ordering Completed!');
 
     return {
       publicInputs: result,

yarn-project/sequencer-client/src/block_builder/solo_block_builder.test.ts

@@ -291,8 +291,8 @@ describe('sequencer/solo_block_builder', () => {
   });
 
   describe('circuits simulator', () => {
-    beforeEach(async () => {
-      const simulator = await WasmRollupCircuitSimulator.new();
+    beforeEach(() => {
+      const simulator = new WasmRollupCircuitSimulator();
       const prover = new EmptyRollupProver();
       builder = new SoloBlockBuilder(builderDb, vks, simulator, prover);
     });
@@ -388,7 +388,7 @@ describe('sequencer/solo_block_builder', () => {
 
     // This test specifically tests nullifier values which previously caused e2e_private_token test to fail
     it('e2e_private_token edge case regression test on nullifier values', async () => {
-      const simulator = await WasmRollupCircuitSimulator.new();
+      const simulator = new WasmRollupCircuitSimulator();
       const prover = new EmptyRollupProver();
       builder = new SoloBlockBuilder(builderDb, vks, simulator, prover);
       // update the starting tree

yarn-project/sequencer-client/src/client/sequencer-client.ts

@@ -41,7 +41,7 @@ export class SequencerClient {
     const blockBuilder = new SoloBlockBuilder(
       merkleTreeDb,
       getVerificationKeys(),
-      await WasmRollupCircuitSimulator.new(),
+      new WasmRollupCircuitSimulator(),
       new EmptyRollupProver(),
     );