chore(benchmark): Measure block sync time

.circleci/config.yml

@@ -937,7 +937,7 @@ jobs:
       - run:
           name: "Benchmark"
           command: cond_run_script end-to-end ./scripts/run_tests_local benchmarks/bench_publish_rollup.test.ts
-          environment: { DEBUG: 'aztec:benchmarks:*,aztec:sequencer' }
+          environment: { DEBUG: 'aztec:benchmarks:*,aztec:sequencer,aztec:world_state,aztec:merkle_trees' }
 
   build-docs:
     machine:

scripts/ci/aggregate_e2e_benchmark.js

@@ -11,7 +11,9 @@ const {
   L1_ROLLUP_CALLDATA_SIZE_IN_BYTES,
   L1_ROLLUP_CALLDATA_GAS,
   L1_ROLLUP_EXECUTION_GAS,
-  ROLLUP_PUBLISHED_TO_L1,
+  L2_BLOCK_PROCESSING_TIME,
+  L2_BLOCK_SYNCED,
+  L2_BLOCK_PUBLISHED_TO_L1,
   ROLLUP_SIZES,
   BENCHMARK_FILE_JSON,
 } = require("./benchmark_shared.js");
@@ -44,11 +46,22 @@ function processRollupPublished(entry, results) {
   append(results, L1_ROLLUP_EXECUTION_GAS, bucket, entry.gasUsed);
 }
 
+// Processes an entry with event name 'l2-block-handled' and updates results
+// Skips instances where the block was emitted by the same node where the processing is skipped
+function processRollupBlockSynced(entry, results) {
+  const bucket = entry.txCount;
+  if (!ROLLUP_SIZES.includes(bucket)) return;
+  if (entry.isBlockOurs) return;
+  append(results, L2_BLOCK_PROCESSING_TIME, bucket, entry.duration);
+}
+
 // Processes a parsed entry from a logfile and updates results
 function processEntry(entry, results) {
   switch (entry.eventName) {
-    case ROLLUP_PUBLISHED_TO_L1:
+    case L2_BLOCK_PUBLISHED_TO_L1:
       return processRollupPublished(entry, results);
+    case L2_BLOCK_SYNCED:
+      return processRollupBlockSynced(entry, results);
     default:
       return;
   }
@@ -73,6 +86,8 @@ async function main() {
     }
   }
 
+  console.log(`Collected entries:`, JSON.stringify(results, null, 2));
+
   // For each bucket of each metric compute the average all collected datapoints
   for (const metricName in results) {
     const metric = results[metricName];
@@ -88,6 +103,7 @@ async function main() {
   results.timestamp = new Date().toISOString();
 
   // Write results to disk
+  console.log(`Aggregated results:`, JSON.stringify(results, null, 2));
   fs.writeFileSync(BENCHMARK_FILE_JSON, JSON.stringify(results, null, 2));
 }
 

scripts/ci/benchmark_shared.js

@@ -2,9 +2,11 @@
 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 ROLLUP_PUBLISHED_TO_L1 = "rollup-published-to-l1";
+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
@@ -18,7 +20,9 @@ module.exports = {
   L1_ROLLUP_CALLDATA_SIZE_IN_BYTES,
   L1_ROLLUP_CALLDATA_GAS,
   L1_ROLLUP_EXECUTION_GAS,
-  ROLLUP_PUBLISHED_TO_L1,
+  L2_BLOCK_PROCESSING_TIME,
+  L2_BLOCK_PUBLISHED_TO_L1,
+  L2_BLOCK_SYNCED,
   ROLLUP_SIZES,
   BENCHMARK_FILE_JSON,
 };

yarn-project/aztec-node/src/aztec-node/config.ts

@@ -6,18 +6,25 @@ import { getConfigEnvVars as getWorldStateVars } from '@aztec/world-state';
 /**
  * The configuration the aztec node.
  */
-export type AztecNodeConfig = ArchiverConfig & SequencerClientConfig & P2PConfig;
+export type AztecNodeConfig = ArchiverConfig &
+  SequencerClientConfig &
+  P2PConfig & {
+    /** Whether the sequencer is disabled for this node. */
+    disableSequencer: boolean;
+  };
 
 /**
  * Returns the config of the aztec node from environment variables with reasonable defaults.
  * @returns A valid aztec node config.
  */
 export function getConfigEnvVars(): AztecNodeConfig {
+  const { SEQ_DISABLED } = process.env;
   const allEnvVars: AztecNodeConfig = {
     ...getSequencerVars(),
     ...getArchiverVars(),
     ...getP2PConfigEnvVars(),
     ...getWorldStateVars(),
+    disableSequencer: !!SEQ_DISABLED,
   };
 
   return allEnvVars;

yarn-project/aztec-node/src/aztec-node/server.ts

@@ -63,7 +63,7 @@ export class AztecNodeService implements AztecNode {
     protected readonly contractDataSource: ContractDataSource,
     protected readonly l1ToL2MessageSource: L1ToL2MessageSource,
     protected readonly worldStateSynchronizer: WorldStateSynchronizer,
-    protected readonly sequencer: SequencerClient,
+    protected readonly sequencer: SequencerClient | undefined,
     protected readonly chainId: number,
     protected readonly version: number,
     protected readonly globalVariableBuilder: GlobalVariableBuilder,
@@ -97,14 +97,10 @@ export class AztecNodeService implements AztecNode {
     await Promise.all([p2pClient.start(), worldStateSynchronizer.start()]);
 
     // now create the sequencer
-    const sequencer = await SequencerClient.new(
-      config,
-      p2pClient,
-      worldStateSynchronizer,
-      archiver,
-      archiver,
-      archiver,
-    );
+    const sequencer = config.disableSequencer
+      ? undefined
+      : await SequencerClient.new(config, p2pClient, worldStateSynchronizer, archiver, archiver, archiver);
+
     return new AztecNodeService(
       config,
       p2pClient,
@@ -126,7 +122,7 @@ export class AztecNodeService implements AztecNode {
    * Returns the sequencer client instance.
    * @returns The sequencer client instance.
    */
-  public getSequencer(): SequencerClient {
+  public getSequencer(): SequencerClient | undefined {
     return this.sequencer;
   }
 
@@ -237,7 +233,8 @@ export class AztecNodeService implements AztecNode {
    * Method to stop the aztec node.
    */
   public async stop() {
-    await this.sequencer.stop();
+    this.log.info(`Stopping`);
+    await this.sequencer?.stop();
     await this.p2pClient.stop();
     await this.worldStateSynchronizer.stop();
     await this.blockSource.stop();

yarn-project/end-to-end/.gitignore

@@ -1 +1,2 @@
-addresses.json
+addresses.json
+/log

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

@@ -1,4 +1,5 @@
 /* eslint-disable camelcase */
+import { AztecNodeService } from '@aztec/aztec-node';
 import { AztecAddress } from '@aztec/aztec.js';
 import { sleep } from '@aztec/foundation/sleep';
 import { TokenContract } from '@aztec/noir-contracts/types';
@@ -20,30 +21,36 @@ describe('benchmarks/publish_rollup', () => {
     [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();
-    await context.aztecNode?.getSequencer().stop();
+    await context.aztecNode?.getSequencer()!.stop();
   }, 60_000);
 
   it.each(ROLLUP_SIZES)(
     `publishes a rollup with %d txs`,
     async (txCount: number) => {
       context.logger(`Assembling rollup with ${txCount} txs`);
-      // Simulate and simultaneously send %d txs. These should not yet be processed since sequencer is stopped.
+      // 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));
       calls.forEach(call => call.simulate({ skipPublicSimulation: true }));
       const sentTxs = calls.map(call => call.send());
+
       // Awaiting txHash waits until the aztec node has received the tx into its p2p pool
       await Promise.all(sentTxs.map(tx => tx.getTxHash()));
       // And then wait a bit more just in case
       await sleep(100);
+
       // Restart sequencer to process all txs together
-      context.aztecNode?.getSequencer().restart();
-      // Wait for the last tx to be processed
+      context.aztecNode?.getSequencer()!.restart();
+      // Wait for the last tx to be processed and finish the current node
       await sentTxs[sentTxs.length - 1].wait({ timeout: 600_00 });
+      await context.teardown();
+
+      // Create a new aztec node to measure sync time of the block
+      context.logger(`Starting new aztec node`);
+      const node = await AztecNodeService.createAndSync({ ...context.config, disableSequencer: true });
+      // Force a sync with world state to ensure new node has caught up before killing it
+      await node.getTreeRoots();
+      await node.stop();
     },
     10 * 60_000,
   );
-
-  afterEach(async () => {
-    await context.teardown();
-  }, 60_000);
 });

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

@@ -1,5 +1,5 @@
 /** Structured log data to include with the message. */
-export type LogData = Record<string, string | number | bigint>;
+export type LogData = Record<string, string | number | bigint | boolean>;
 
 /** A callable logger instance. */
 export type LogFn = (msg: string, data?: LogData) => void;

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

@@ -0,0 +1,12 @@
+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.
+ */
+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];
+}

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

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

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

@@ -145,12 +145,7 @@ export class L1Publisher implements L2BlockReceiver {
         const stats: L1PublishStats = {
           ...pick(receipt, 'gasPrice', 'gasUsed', 'transactionHash'),
           ...pick(tx!, 'calldataGas', 'calldataSize'),
-          txCount: l2BlockData.numberOfTxs,
-          blockNumber: l2BlockData.number,
-          encryptedLogCount: l2BlockData.newEncryptedLogs?.getTotalLogCount() ?? 0,
-          unencryptedLogCount: l2BlockData.newUnencryptedLogs?.getTotalLogCount() ?? 0,
-          encryptedLogSize: l2BlockData.newEncryptedLogs?.getSerializedLength() ?? 0,
-          unencryptedLogSize: l2BlockData.newUnencryptedLogs?.getSerializedLength() ?? 0,
+          ...l2BlockData.getStats(),
           eventName: 'rollup-published-to-l1',
         };
         this.log.info(`Published L2 block to L1 rollup contract`, stats);

yarn-project/types/src/l2_block.ts

@@ -809,6 +809,21 @@ export class L2Block {
       .map((_, i) => this.getTx(i));
   }
 
+  /**
+   * Returns stats used for logging.
+   * @returns Stats on tx count, number, and log size and count.
+   */
+  getStats() {
+    return {
+      txCount: this.numberOfTxs,
+      blockNumber: this.number,
+      encryptedLogCount: this.newEncryptedLogs?.getTotalLogCount() ?? 0,
+      unencryptedLogCount: this.newUnencryptedLogs?.getTotalLogCount() ?? 0,
+      encryptedLogSize: this.newEncryptedLogs?.getSerializedLength() ?? 0,
+      unencryptedLogSize: this.newUnencryptedLogs?.getSerializedLength() ?? 0,
+    };
+  }
+
   /**
    * Inspect for debugging purposes..
    * @param maxBufferSize - The number of bytes to be extracted from buffer.

yarn-project/world-state/package.json

@@ -48,6 +48,7 @@
     "@types/memdown": "^3.0.0",
     "@types/node": "^18.7.23",
     "jest": "^29.5.0",
+    "jest-mock-extended": "^3.0.5",
     "memdown": "^6.1.1",
     "ts-jest": "^29.1.0",
     "ts-node": "^10.9.1",

yarn-project/world-state/src/merkle-tree/merkle_tree_operations_facade.ts

@@ -2,7 +2,14 @@ import { Fr } from '@aztec/foundation/fields';
 import { LowLeafWitnessData } from '@aztec/merkle-tree';
 import { L2Block, MerkleTreeId, SiblingPath } from '@aztec/types';
 
-import { CurrentTreeRoots, LeafData, MerkleTreeDb, MerkleTreeOperations, TreeInfo } from '../index.js';
+import {
+  CurrentTreeRoots,
+  HandleL2BlockResult,
+  LeafData,
+  MerkleTreeDb,
+  MerkleTreeOperations,
+  TreeInfo,
+} from '../index.js';
 
 /**
  * Wraps a MerkleTreeDbOperations to call all functions with a preset includeUncommitted flag.
@@ -142,9 +149,9 @@ export class MerkleTreeOperationsFacade implements MerkleTreeOperations {
   /**
    * Handles a single L2 block (i.e. Inserts the new commitments into the merkle tree).
    * @param block - The L2 block to handle.
-   * @returns Empty promise.
+   * @returns Whether the block handled was produced by this same node.
    */
-  public handleL2Block(block: L2Block): Promise<void> {
+  public handleL2Block(block: L2Block): Promise<HandleL2BlockResult> {
     return this.trees.handleL2Block(block);
   }