chore(avm): add bytecode size metrics (#7042)

noir-projects/aztec-nr/aztec/src/context/private_context.nr

@@ -193,10 +193,10 @@ impl PrivateContext {
     }
 
     pub fn end_setup(&mut self) {
-        dep::protocol_types::debug_log::debug_log_format(
-            "Ending setup at counter {0}",
-            [self.side_effect_counter as Field]
-        );
+        // dep::protocol_types::debug_log::debug_log_format(
+        //     "Ending setup at counter {0}",
+        //     [self.side_effect_counter as Field]
+        // );
         self.min_revertible_side_effect_counter = self.side_effect_counter;
     }
 

yarn-project/circuit-types/src/stats/metrics.ts

@@ -34,7 +34,13 @@ export const Metrics = [
   {
     name: 'avm_simulation_time_ms',
     groupBy: 'app-circuit-name',
-    description: 'Time to simulate an AVM circuit.',
+    description: 'Time to simulate an AVM program.',
+    events: ['avm-simulation'],
+  },
+  {
+    name: 'avm_simulation_bytecode_size_in_bytes',
+    groupBy: 'app-circuit-name',
+    description: 'Uncompressed bytecode size for an AVM program.',
     events: ['avm-simulation'],
   },
   {

yarn-project/circuit-types/src/stats/stats.ts

@@ -112,6 +112,8 @@ export type AvmSimulationStats = {
   appCircuitName: string;
   /** Duration in ms. */
   duration: number;
+  /** Uncompressed bytecode size. */
+  bytecodeSize: number;
 };
 
 /** Stats for witness generation. */

yarn-project/scripts/src/benchmarks/aggregate.ts

@@ -153,6 +153,7 @@ function processCircuitProving(entry: CircuitProvingStats, results: BenchmarkCol
 
 function processAvmSimulation(entry: AvmSimulationStats, results: BenchmarkCollectedResults) {
   append(results, 'avm_simulation_time_ms', entry.appCircuitName, entry.duration);
+  append(results, 'avm_simulation_bytecode_size_in_bytes', entry.appCircuitName, entry.bytecodeSize);
 }
 
 function processDbAccess(entry: PublicDBAccessStats, results: BenchmarkCollectedResults) {

yarn-project/scripts/src/benchmarks/markdown.ts

@@ -192,6 +192,7 @@ export function getMarkdown(prNumber: number) {
   const kernelCircuitMetrics = Metrics.filter(m => m.groupBy === 'protocol-circuit-name').map(m => m.name);
   const appCircuitMetrics = Metrics.filter(m => m.groupBy === 'app-circuit-name')
     .filter(m => m.name !== 'avm_simulation_time_ms')
+    .filter(m => m.name !== 'avm_simulation_bytecode_size_in_bytes')
     .map(m => m.name);
   const metricsByClassesRegistered = Metrics.filter(m => m.groupBy === 'classes-registered').map(m => m.name);
   const metricsByFeePaymentMethod = Metrics.filter(m => m.groupBy === 'fee-payment-method').map(m => m.name);
@@ -260,7 +261,7 @@ ${getTableContent(
 
 Time to simulate various public functions in the AVM.
 ${getTableContent(
-  transpose(pick(benchmark, ['avm_simulation_time_ms'])),
+  transpose(pick(benchmark, ['avm_simulation_time_ms', 'avm_simulation_bytecode_size_in_bytes'])),
   transpose(baseBenchmark),
   '',
   'Function',

yarn-project/simulator/src/public/executor.ts

@@ -70,18 +70,22 @@ export class PublicExecutor {
     const avmContext = new AvmContext(worldStateJournal, executionEnv, machineState);
     const simulator = new AvmSimulator(avmContext);
     const avmResult = await simulator.execute();
+    const bytecode = simulator.getBytecode();
 
     // Commit the journals state to the DBs since this is a top-level execution.
     // Observe that this will write all the state changes to the DBs, not only the latest for each slot.
     // However, the underlying DB keep a cache and will only write the latest state to disk.
     await avmContext.persistableState.publicStorage.commitToDB();
 
     PublicExecutor.log.verbose(
-      `[AVM] ${fnName} returned, reverted: ${avmResult.reverted}, reason: ${avmResult.revertReason}.`,
+      `[AVM] ${fnName} returned, reverted: ${avmResult.reverted}${
+        avmResult.reverted ? ', reason: ' + avmResult.revertReason : ''
+      }.`,
       {
         eventName: 'avm-simulation',
         appCircuitName: fnName ?? 'unknown',
         duration: timer.ms(),
+        bytecodeSize: bytecode!.length,
       } satisfies AvmSimulationStats,
     );
 
@@ -91,7 +95,7 @@ export class PublicExecutor {
       execution,
       startGas,
       avmContext,
-      simulator.getBytecode(),
+      bytecode,
     );
 
     // TODO(https://github.com/AztecProtocol/aztec-packages/issues/5818): is this really needed?

yarn-project/simulator/src/public/public_db_sources.ts

@@ -239,7 +239,7 @@ export class WorldStateDB implements CommitmentsDB {
       return undefined;
     }
 
-    this.log.verbose(`[DB] Fetched nullifier membership`, {
+    this.log.debug(`[DB] Fetched nullifier membership`, {
       eventName: 'public-db-access',
       duration: timer.ms(),
       operation: 'get-nullifier-membership-witness-at-latest-block',
@@ -277,7 +277,7 @@ export class WorldStateDB implements CommitmentsDB {
       messageIndex,
     );
 
-    this.log.verbose(`[DB] Fetched L1 to L2 message membership`, {
+    this.log.debug(`[DB] Fetched L1 to L2 message membership`, {
       eventName: 'public-db-access',
       duration: timer.ms(),
       operation: 'get-l1-to-l2-message-membership-witness',
@@ -289,7 +289,7 @@ export class WorldStateDB implements CommitmentsDB {
   public async getL1ToL2LeafValue(leafIndex: bigint): Promise<Fr | undefined> {
     const timer = new Timer();
     const leafValue = await this.db.getLeafValue(MerkleTreeId.L1_TO_L2_MESSAGE_TREE, leafIndex);
-    this.log.verbose(`[DB] Fetched L1 to L2 message leaf value`, {
+    this.log.debug(`[DB] Fetched L1 to L2 message leaf value`, {
       eventName: 'public-db-access',
       duration: timer.ms(),
       operation: 'get-l1-to-l2-message-leaf-value',
@@ -300,7 +300,7 @@ export class WorldStateDB implements CommitmentsDB {
   public async getCommitmentIndex(commitment: Fr): Promise<bigint | undefined> {
     const timer = new Timer();
     const index = await this.db.findLeafIndex(MerkleTreeId.NOTE_HASH_TREE, commitment);
-    this.log.verbose(`[DB] Fetched commitment index`, {
+    this.log.debug(`[DB] Fetched commitment index`, {
       eventName: 'public-db-access',
       duration: timer.ms(),
       operation: 'get-commitment-index',
@@ -311,7 +311,7 @@ export class WorldStateDB implements CommitmentsDB {
   public async getNullifierIndex(nullifier: Fr): Promise<bigint | undefined> {
     const timer = new Timer();
     const index = await this.db.findLeafIndex(MerkleTreeId.NULLIFIER_TREE, nullifier.toBuffer());
-    this.log.verbose(`[DB] Fetched nullifier index`, {
+    this.log.debug(`[DB] Fetched nullifier index`, {
       eventName: 'public-db-access',
       duration: timer.ms(),
       operation: 'get-nullifier-index',