From 1e2825c4ec4299f863820fc4d0b8e7624e8c5a45 Mon Sep 17 00:00:00 2001
From: fcarreiro <facundo@aztecprotocol.com>
Date: Tue, 2 Apr 2024 16:37:34 +0000
Subject: [PATCH] chore(avm): logging changes

---
 yarn-project/end-to-end/package.json          |  2 +-
 .../simulator/src/avm/avm_simulator.ts        | 28 ++++++++++++++++++-
 2 files changed, 28 insertions(+), 2 deletions(-)

diff --git a/yarn-project/end-to-end/package.json b/yarn-project/end-to-end/package.json
index 00f3077716b..0e953c68989 100644
--- a/yarn-project/end-to-end/package.json
+++ b/yarn-project/end-to-end/package.json
@@ -11,7 +11,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 $(yarn 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 $(yarn 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 $(yarn 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
index 2448b5e1baf..4c2de15f523 100644
--- 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;
     }
   }