chore(avm): logging changes

AztecProtocol · Apr 4, 2024 · c14dc40 · c14dc40
1 parent 4ca58c7
commit c14dc40
Show file tree

Hide file tree

Showing 2 changed files with 28 additions and 2 deletions.
diff --git a/yarn-project/end-to-end/package.json b/yarn-project/end-to-end/package.json
@@ -15,7 +15,7 @@
     "clean": "rm -rf ./dest .tsbuildinfo",
     "formatting": "run -T prettier --check ./src \"!src/web/main.js\" && run -T eslint ./src",
     "formatting:fix": "run -T eslint --fix ./src && run -T prettier -w ./src",
-    "test": "DEBUG='aztec:*' NODE_NO_WARNINGS=1 node --experimental-vm-modules ../node_modules/.bin/jest --runInBand --testTimeout=60000 --forceExit",
+    "test": "DEBUG='aztec:*,-aztec:avm_simulator:memory,-aztec:avm_simulator:*:instruction' NODE_NO_WARNINGS=1 node --experimental-vm-modules ../node_modules/.bin/jest --runInBand --testTimeout=60000 --forceExit",
     "test:integration": "concurrently -k -s first -c reset,dim -n test,anvil \"yarn test:integration:run\" \"anvil\"",
     "test:integration:run": "NODE_NO_WARNINGS=1 node --experimental-vm-modules ../node_modules/.bin/jest --no-cache --runInBand --config jest.integration.config.json"
   },

diff --git a/yarn-project/simulator/src/avm/avm_simulator.ts b/yarn-project/simulator/src/avm/avm_simulator.ts
@@ -10,11 +10,15 @@ import { decodeFromBytecode } from './serialization/bytecode_serialization.js';
 
 export class AvmSimulator {
   private log: DebugLogger;
+  private logInstruction: DebugLogger;
 
   constructor(private context: AvmContext) {
     this.log = createDebugLogger(
       `aztec:avm_simulator:core(f:${context.environment.temporaryFunctionSelector.toString()})`,
     );
+    this.logInstruction = createDebugLogger(
+      `aztec:avm_simulator:core(f:${context.environment.temporaryFunctionSelector.toString()}):instruction`,
+    );
   }
 
   /**
@@ -50,6 +54,15 @@ export class AvmSimulator {
    */
   public async executeInstructions(instructions: Instruction[]): Promise<AvmContractCallResults> {
     assert(instructions.length > 0);
+    // For stats only.
+    let executedInstructions: bigint = 0n;
+    const initialGas = {
+      l1GasLeft: this.context.machineState.l1GasLeft,
+      l2GasLeft: this.context.machineState.l2GasLeft,
+      daGasLeft: this.context.machineState.daGasLeft,
+    };
+    const startingTime = Date.now();
+
     try {
       // Execute instruction pointed to by the current program counter
       // continuing until the machine state signifies a halt
@@ -60,11 +73,12 @@ export class AvmSimulator {
           'AVM attempted to execute non-existent instruction. This should never happen (invalid bytecode or AVM simulator bug)!',
         );
 
-        this.log.debug(`@${this.context.machineState.pc} ${instruction.toString()}`);
+        this.logInstruction(`@${this.context.machineState.pc} ${instruction.toString()}`);
         // Execute the instruction.
         // Normal returns and reverts will return normally here.
         // "Exceptional halts" will throw.
         await instruction.run(this.context);
+        executedInstructions++;
 
         if (this.context.machineState.pc >= instructions.length) {
           this.log('Passed end of program!');
@@ -75,6 +89,12 @@ export class AvmSimulator {
       // Return results for processing by calling context
       const results = this.context.machineState.getResults();
       this.log(`Context execution results: ${results.toString()}`);
+      this.log(`Executed ${executedInstructions} instructions in ${Date.now() - startingTime}ms.`);
+      this.log(
+        `Gas consumed: { l1: ${initialGas.l1GasLeft - this.context.machineState.l1GasLeft}, l2: ${
+          initialGas.l2GasLeft - this.context.machineState.l2GasLeft
+        }, da: ${initialGas.daGasLeft - this.context.machineState.daGasLeft} }`,
+      );
       return results;
     } catch (e) {
       this.log('Exceptional halt');
@@ -87,6 +107,12 @@ export class AvmSimulator {
       // Note: "exceptional halts" cannot return data
       const results = new AvmContractCallResults(/*reverted=*/ true, /*output=*/ [], /*revertReason=*/ e);
       this.log(`Context execution results: ${results.toString()}`);
+      this.log(`Executed ${executedInstructions} instructions in ${Date.now() - startingTime}ms.`);
+      this.log(
+        `Gas consumed: { l1: ${initialGas.l1GasLeft - this.context.machineState.l1GasLeft}, l2: ${
+          initialGas.l2GasLeft - this.context.machineState.l2GasLeft
+        }, da: ${initialGas.daGasLeft - this.context.machineState.daGasLeft} }`,
+      );
       return results;
     }
   }