fix: displaying debug logs from public function simulations

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

@@ -1172,7 +1172,7 @@ export class AztecNodeService implements AztecNode, AztecNodeAdmin, Traceable {
       const processor = publicProcessorFactory.create(merkleTreeFork, newGlobalVariables, config);
 
       // REFACTOR: Consider merging ProcessReturnValues into ProcessedTx
-      const [processedTxs, failedTxs, _usedTxs, returns] = await processor.process([tx]);
+      const [processedTxs, failedTxs, _usedTxs, returns, _blobFields, debugLogs] = await processor.process([tx]);
       // REFACTOR: Consider returning the error rather than throwing
       if (failedTxs.length) {
         this.log.warn(`Simulated tx ${txHash} fails: ${failedTxs[0].error}`, { txHash });
@@ -1186,6 +1186,7 @@ export class AztecNodeService implements AztecNode, AztecNodeAdmin, Traceable {
         processedTx.txEffect,
         returns,
         processedTx.gasUsed,
+        debugLogs,
       );
     } finally {
       await merkleTreeFork.close();

yarn-project/prover-node/src/job/epoch-proving-job.test.ts

@@ -134,7 +134,7 @@ describe('epoch-proving-job', () => {
     publicProcessor.process.mockImplementation(async txs => {
       const txsArray = await toArray(txs);
       const processedTxs = await Promise.all(txsArray.map(tx => mock<ProcessedTx>({ hash: tx.getTxHash() })));
-      return [processedTxs, [], txsArray, [], 0];
+      return [processedTxs, [], txsArray, [], 0, []];
     });
   });
 
@@ -179,7 +179,7 @@ describe('epoch-proving-job', () => {
     publicProcessor.process.mockImplementation(async txs => {
       const txsArray = await toArray(txs);
       const errors = txsArray.map(tx => ({ error: new Error('Failed to process tx'), tx }));
-      return [[], errors, [], [], 0];
+      return [[], errors, [], [], 0, []];
     });
 
     const job = createJob();
@@ -190,7 +190,7 @@ describe('epoch-proving-job', () => {
   });
 
   it('fails if does not process all txs for a block', async () => {
-    publicProcessor.process.mockImplementation(_txs => Promise.resolve([[], [], [], [], 0]));
+    publicProcessor.process.mockImplementation(_txs => Promise.resolve([[], [], [], [], 0, []]));
 
     const job = createJob();
     await job.run();

yarn-project/pxe/src/contract_function_simulator/oracle/utility_execution_oracle.ts

@@ -3,7 +3,7 @@ import type { BlockNumber } from '@aztec/foundation/branded-types';
 import { Aes128 } from '@aztec/foundation/crypto/aes128';
 import { Fr } from '@aztec/foundation/curves/bn254';
 import { Point } from '@aztec/foundation/curves/grumpkin';
-import { LogLevels, type Logger, applyStringFormatting, createLogger } from '@aztec/foundation/log';
+import { LogLevels, type Logger, createLogger } from '@aztec/foundation/log';
 import type { MembershipWitness } from '@aztec/foundation/trees';
 import type { KeyStore } from '@aztec/key-store';
 import type { AuthWitness } from '@aztec/stdlib/auth-witness';
@@ -21,6 +21,7 @@ import { MerkleTreeId, type NullifierMembershipWitness, PublicDataWitness } from
 import type { BlockHeader, Capsule } from '@aztec/stdlib/tx';
 
 import type { AccessScopes } from '../../access_scopes.js';
+import { createContractLogger, logContractMessage } from '../../contract_logging.js';
 import { EventService } from '../../events/event_service.js';
 import { LogService } from '../../logs/log_service.js';
 import { NoteService } from '../../notes/note_service.js';
@@ -402,12 +403,13 @@ export class UtilityExecutionOracle implements IMiscOracle, IUtilityExecutionOra
    */
   async #getContractLogger(): Promise<Logger> {
     if (!this.contractLogger) {
-      const addrAbbrev = this.contractAddress.toString().slice(0, 10);
-      const name = await this.contractStore.getDebugContractName(this.contractAddress);
-      const module = name ? `contract_log::${name}(${addrAbbrev})` : `contract_log::${addrAbbrev}`;
       // Purpose of instanceId is to distinguish logs from different instances of the same component. It makes sense
       // to re-use jobId as instanceId here as executions of different PXE jobs are isolated.
-      this.contractLogger = createLogger(module, { instanceId: this.jobId });
+      this.contractLogger = await createContractLogger(
+        this.contractAddress,
+        addr => this.contractStore.getDebugContractName(addr),
+        { instanceId: this.jobId },
+      );
     }
     return this.contractLogger;
   }
@@ -416,9 +418,8 @@ export class UtilityExecutionOracle implements IMiscOracle, IUtilityExecutionOra
     if (!LogLevels[level]) {
       throw new Error(`Invalid log level: ${level}`);
     }
-    const levelName = LogLevels[level];
     const logger = await this.#getContractLogger();
-    logger[levelName](`${applyStringFormatting(message, fields)}`);
+    logContractMessage(logger, LogLevels[level], message, fields);
   }
 
   public async utilityFetchTaggedLogs(pendingTaggedLogArrayBaseSlot: Fr) {

yarn-project/pxe/src/contract_logging.ts

@@ -0,0 +1,39 @@
+import type { Fr } from '@aztec/foundation/curves/bn254';
+import { type LogLevel, type Logger, applyStringFormatting, createLogger } from '@aztec/foundation/log';
+import type { AztecAddress } from '@aztec/stdlib/aztec-address';
+import type { DebugLog } from '@aztec/stdlib/logs';
+
+/** Resolves a contract address to a human-readable name, if available. */
+export type ContractNameResolver = (address: AztecAddress) => Promise<string | undefined>;
+
+/**
+ * Creates a logger whose output is prefixed with `contract_log::<name>(<addrAbbrev>)`.
+ */
+export async function createContractLogger(
+  contractAddress: AztecAddress,
+  getContractName: ContractNameResolver,
+  options?: { instanceId?: string },
+): Promise<Logger> {
+  const addrAbbrev = contractAddress.toString().slice(0, 10);
+  const name = await getContractName(contractAddress);
+  const module = name ? `contract_log::${name}(${addrAbbrev})` : `contract_log::Unknown(${addrAbbrev})`;
+  return createLogger(module, options);
+}
+
+/**
+ * Formats and emits a single contract log message through the given logger.
+ */
+export function logContractMessage(logger: Logger, level: LogLevel, message: string, fields: Fr[]): void {
+  logger[level](applyStringFormatting(message, fields));
+}
+
+/**
+ * Displays debug logs collected during public function simulation,
+ * using the `contract_log::` prefixed logger format.
+ */
+export async function displayDebugLogs(debugLogs: DebugLog[], getContractName: ContractNameResolver): Promise<void> {
+  for (const log of debugLogs) {
+    const logger = await createContractLogger(log.contractAddress, getContractName);
+    logContractMessage(logger, log.level, log.message, log.fields);
+  }
+}

yarn-project/pxe/src/entrypoints/client/bundle/index.ts

@@ -3,6 +3,7 @@ export * from '../../../notes_filter.js';
 export * from '../../../pxe.js';
 export * from '../../../config/index.js';
 export * from '../../../error_enriching.js';
+export * from '../../../contract_logging.js';
 export * from '../../../storage/index.js';
 export * from './utils.js';
 export type { PXECreationOptions } from '../../pxe_creation_options.js';

yarn-project/pxe/src/entrypoints/client/lazy/index.ts

@@ -4,5 +4,6 @@ export * from '../../../pxe.js';
 export * from '../../../config/index.js';
 export * from '../../../storage/index.js';
 export * from '../../../error_enriching.js';
+export * from '../../../contract_logging.js';
 export * from './utils.js';
 export { type PXECreationOptions } from '../../pxe_creation_options.js';

yarn-project/pxe/src/pxe.ts

@@ -61,6 +61,7 @@ import {
   generateSimulatedProvingResult,
 } from './contract_function_simulator/contract_function_simulator.js';
 import { ProxiedContractStoreFactory } from './contract_function_simulator/proxied_contract_data_source.js';
+import { displayDebugLogs } from './contract_logging.js';
 import { ContractSyncService } from './contract_sync/contract_sync_service.js';
 import { readCurrentClassId } from './contract_sync/helpers.js';
 import { PXEDebugUtils } from './debug/pxe_debug_utils.js';
@@ -947,6 +948,9 @@ export class PXE {
           const publicSimulationTimer = new Timer();
           publicOutput = await this.#simulatePublicCalls(simulatedTx, skipFeeEnforcement);
           publicSimulationTime = publicSimulationTimer.ms();
+          if (publicOutput?.debugLogs?.length) {
+            await displayDebugLogs(publicOutput.debugLogs, addr => this.contractStore.getDebugContractName(addr));
+          }
         }
 
         let validationTime: number | undefined;

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

@@ -25,6 +25,7 @@ import type {
   PublicProcessorValidator,
   SequencerConfig,
 } from '@aztec/stdlib/interfaces/server';
+import type { DebugLog } from '@aztec/stdlib/logs';
 import { ProvingRequestType } from '@aztec/stdlib/proofs';
 import { MerkleTreeId } from '@aztec/stdlib/trees';
 import {
@@ -130,7 +131,6 @@ class PublicProcessorTimeoutError extends Error {
  */
 export class PublicProcessor implements Traceable {
   private metrics: PublicProcessorMetrics;
-
   constructor(
     protected globalVariables: GlobalVariables,
     private guardedMerkleTree: GuardedMerkleTreeOperations,
@@ -159,12 +159,13 @@ export class PublicProcessor implements Traceable {
     txs: Iterable<Tx> | AsyncIterable<Tx>,
     limits: PublicProcessorLimits = {},
     validator: PublicProcessorValidator = {},
-  ): Promise<[ProcessedTx[], FailedTx[], Tx[], NestedProcessReturnValues[], number]> {
+  ): Promise<[ProcessedTx[], FailedTx[], Tx[], NestedProcessReturnValues[], number, DebugLog[]]> {
     const { maxTransactions, maxBlockSize, deadline, maxBlockGas, maxBlobFields } = limits;
     const { preprocessValidator, nullifierCache } = validator;
     const result: ProcessedTx[] = [];
     const usedTxs: Tx[] = [];
     const failed: FailedTx[] = [];
+    const debugLogs: DebugLog[] = [];
     const timer = new Timer();
 
     let totalSizeInBytes = 0;
@@ -241,7 +242,7 @@ export class PublicProcessor implements Traceable {
       this.contractsDB.createCheckpoint();
 
       try {
-        const [processedTx, returnValues] = await this.processTx(tx, deadline);
+        const [processedTx, returnValues, txDebugLogs] = await this.processTx(tx, deadline);
 
         // Inject a fake processing failure after N txs if requested
         const fakeThrowAfter = this.opts.fakeThrowAfterProcessingTxCount;
@@ -290,6 +291,7 @@ export class PublicProcessor implements Traceable {
         result.push(processedTx);
         usedTxs.push(tx);
         returns = returns.concat(returnValues);
+        debugLogs.push(...txDebugLogs);
 
         totalPublicGas = totalPublicGas.add(processedTx.gasUsed.publicGas);
         totalBlockGas = totalBlockGas.add(processedTx.gasUsed.totalGas);
@@ -363,7 +365,7 @@ export class PublicProcessor implements Traceable {
       totalSizeInBytes,
     });
 
-    return [result, failed, usedTxs, returns, totalBlobFields];
+    return [result, failed, usedTxs, returns, totalBlobFields, debugLogs];
   }
 
   private async checkWorldStateUnchanged(
@@ -383,8 +385,13 @@ export class PublicProcessor implements Traceable {
   }
 
   @trackSpan('PublicProcessor.processTx', tx => ({ [Attributes.TX_HASH]: tx.getTxHash().toString() }))
-  private async processTx(tx: Tx, deadline: Date | undefined): Promise<[ProcessedTx, NestedProcessReturnValues[]]> {
-    const [time, [processedTx, returnValues]] = await elapsed(() => this.processTxWithinDeadline(tx, deadline));
+  private async processTx(
+    tx: Tx,
+    deadline: Date | undefined,
+  ): Promise<[ProcessedTx, NestedProcessReturnValues[], DebugLog[]]> {
+    const [time, [processedTx, returnValues, debugLogs]] = await elapsed(() =>
+      this.processTxWithinDeadline(tx, deadline),
+    );
 
     this.log.verbose(
       !tx.hasPublicCalls()
@@ -407,7 +414,7 @@ export class PublicProcessor implements Traceable {
       },
     );
 
-    return [processedTx, returnValues ?? []];
+    return [processedTx, returnValues ?? [], debugLogs];
   }
 
   private async doTreeInsertionsForPrivateOnlyTx(processedTx: ProcessedTx): Promise<void> {
@@ -441,10 +448,9 @@ export class PublicProcessor implements Traceable {
   private async processTxWithinDeadline(
     tx: Tx,
     deadline: Date | undefined,
-  ): Promise<[ProcessedTx, NestedProcessReturnValues[] | undefined]> {
-    const innerProcessFn: () => Promise<[ProcessedTx, NestedProcessReturnValues[] | undefined]> = tx.hasPublicCalls()
-      ? () => this.processTxWithPublicCalls(tx)
-      : () => this.processPrivateOnlyTx(tx);
+  ): Promise<[ProcessedTx, NestedProcessReturnValues[] | undefined, DebugLog[]]> {
+    const innerProcessFn: () => Promise<[ProcessedTx, NestedProcessReturnValues[] | undefined, DebugLog[]]> =
+      tx.hasPublicCalls() ? () => this.processTxWithPublicCalls(tx) : () => this.processPrivateOnlyTx(tx);
 
     // Fake a delay per tx if instructed (used for tests)
     const fakeDelayPerTxMs = this.opts.fakeProcessingDelayPerTxMs;
@@ -512,7 +518,7 @@ export class PublicProcessor implements Traceable {
   @trackSpan('PublicProcessor.processPrivateOnlyTx', (tx: Tx) => ({
     [Attributes.TX_HASH]: tx.getTxHash().toString(),
   }))
-  private async processPrivateOnlyTx(tx: Tx): Promise<[ProcessedTx, undefined]> {
+  private async processPrivateOnlyTx(tx: Tx): Promise<[ProcessedTx, undefined, DebugLog[]]> {
     const gasFees = this.globalVariables.gasFees;
     const transactionFee = computeTransactionFee(gasFees, tx.data.constants.txContext.gasSettings, tx.data.gasUsed);
 
@@ -537,13 +543,13 @@ export class PublicProcessor implements Traceable {
 
     await this.contractsDB.addNewContracts(tx);
 
-    return [processedTx, undefined];
+    return [processedTx, undefined, []];
   }
 
   @trackSpan('PublicProcessor.processTxWithPublicCalls', tx => ({
     [Attributes.TX_HASH]: tx.getTxHash().toString(),
   }))
-  private async processTxWithPublicCalls(tx: Tx): Promise<[ProcessedTx, NestedProcessReturnValues[]]> {
+  private async processTxWithPublicCalls(tx: Tx): Promise<[ProcessedTx, NestedProcessReturnValues[], DebugLog[]]> {
     const timer = new Timer();
 
     const result = await this.publicTxSimulator.simulate(tx);
@@ -581,7 +587,7 @@ export class PublicProcessor implements Traceable {
       revertReason,
     );
 
-    return [processedTx, appLogicReturnValues];
+    return [processedTx, appLogicReturnValues, result.logs ?? []];
   }
 
   /**

yarn-project/stdlib/src/tx/public_simulation_output.ts

@@ -7,6 +7,7 @@ import { z } from 'zod';
 import { SimulationError } from '../errors/simulation_error.js';
 import { Gas } from '../gas/gas.js';
 import type { GasUsed } from '../gas/gas_used.js';
+import { DebugLog } from '../logs/debug_log.js';
 import { NullishToUndefined } from '../schemas/schemas.js';
 import { TxEffect } from '../tx/tx_effect.js';
 import { GlobalVariables } from './global_variables.js';
@@ -71,6 +72,7 @@ export class PublicSimulationOutput {
     public txEffect: TxEffect,
     public publicReturnValues: NestedProcessReturnValues[],
     public gasUsed: GasUsed,
+    public debugLogs: DebugLog[] = [],
   ) {}
 
   static get schema(): ZodFor<PublicSimulationOutput> {
@@ -86,6 +88,7 @@ export class PublicSimulationOutput {
           publicGas: Gas.schema,
           billedGas: Gas.schema,
         }),
+        debugLogs: z.array(DebugLog.schema).default([]),
       })
       .transform(
         fields =>
@@ -95,6 +98,7 @@ export class PublicSimulationOutput {
             fields.txEffect,
             fields.publicReturnValues,
             fields.gasUsed,
+            fields.debugLogs,
           ),
       );
   }

yarn-project/validator-client/src/checkpoint_builder.test.ts

@@ -94,6 +94,7 @@ describe('CheckpointBuilder', () => {
         [], // usedTxs
         [], // returnValues
         0, // usedTxBlobFields
+        [], // debugLogs
       ]);
 
       const result = await checkpointBuilder.buildBlock([], blockNumber, 1000n);
@@ -117,6 +118,7 @@ describe('CheckpointBuilder', () => {
         [], // usedTxs
         [], // returnValues
         0, // usedTxBlobFields
+        [], // debugLogs
       ]);
 
       const result = await checkpointBuilder.buildBlock([], blockNumber, 1000n);
@@ -136,6 +138,7 @@ describe('CheckpointBuilder', () => {
         [], // usedTxs
         [], // returnValues
         0, // usedTxBlobFields
+        [], // debugLogs
       ]);
 
       await expect(checkpointBuilder.buildBlock([], blockNumber, 1000n)).rejects.toThrow(NoValidTxsError);

yarn-project/wallet-sdk/src/base-wallet/base_wallet.test.ts

@@ -88,6 +88,7 @@ describe('BaseWallet', () => {
       txEffect: TxEffect.empty(),
       publicReturnValues: [optimizedRv0, optimizedRv1],
       gasUsed: { totalGas: Gas.empty(), teardownGas: Gas.empty(), publicGas: Gas.empty(), billedGas: Gas.empty() },
+      debugLogs: [],
     };
     node.simulatePublicCalls.mockResolvedValue(optimizedPublicOutput);
 
@@ -98,6 +99,7 @@ describe('BaseWallet', () => {
       txEffect: TxEffect.empty(),
       publicReturnValues: [normalRv0],
       gasUsed: { totalGas: Gas.empty(), teardownGas: Gas.empty(), publicGas: Gas.empty(), billedGas: Gas.empty() },
+      debugLogs: [],
     };
     const normalResult = new TxSimulationResult(
       mock<PrivateExecutionResult>(),

yarn-project/wallet-sdk/src/base-wallet/base_wallet.ts

@@ -28,7 +28,7 @@ import type { ChainInfo } from '@aztec/entrypoints/interfaces';
 import { Fr } from '@aztec/foundation/curves/bn254';
 import { createLogger } from '@aztec/foundation/log';
 import type { FieldsOf } from '@aztec/foundation/types';
-import type { AccessScopes } from '@aztec/pxe/client/lazy';
+import type { AccessScopes, ContractNameResolver } from '@aztec/pxe/client/lazy';
 import type { PXE, PackedPrivateEvent } from '@aztec/pxe/server';
 import {
   type ContractArtifact,
@@ -338,6 +338,15 @@ export abstract class BaseWallet implements Wallet {
       blockHeader = (await this.aztecNode.getBlockHeader())!;
     }
 
+    const getContractName: ContractNameResolver = async address => {
+      const instance = await this.pxe.getContractInstance(address);
+      if (!instance) {
+        return undefined;
+      }
+      const artifact = await this.pxe.getContractArtifact(instance.currentContractClassId);
+      return artifact?.name;
+    };
+
     const [optimizedResults, normalResult] = await Promise.all([
       optimizableCalls.length > 0
         ? simulateViaNode(
@@ -348,6 +357,7 @@ export abstract class BaseWallet implements Wallet {
             feeOptions.gasSettings,
             blockHeader,
             opts.skipFeeEnforcement ?? true,
+            getContractName,
           )
         : Promise.resolve([]),
       remainingCalls.length > 0