chore: Tweak validator logs (#10597)

Tweaks logs in the validator and a few on p2p.

yarn-project/p2p/src/client/p2p_client.ts

@@ -434,9 +434,11 @@ export class P2PClient extends WithTracer implements P2P {
   public async requestTxByHash(txHash: TxHash): Promise<Tx | undefined> {
     const tx = await this.p2pService.sendRequest(TX_REQ_PROTOCOL, txHash);
 
-    this.log.debug(`Requested ${txHash.toString()} from peer | success = ${!!tx}`);
     if (tx) {
+      this.log.debug(`Received tx ${txHash.toString()} from peer`);
       await this.txPool.addTxs([tx]);
+    } else {
+      this.log.debug(`Failed to receive tx ${txHash.toString()} from peer`);
     }
 
     return tx;

yarn-project/p2p/src/mem_pools/tx_pool/aztec_kv_tx_pool.ts

@@ -125,7 +125,7 @@ export class AztecKVTxPool implements TxPool {
       let pendingCount = 0;
       for (const [i, tx] of txs.entries()) {
         const txHash = txHashes[i];
-        this.#log.info(`Adding tx with id ${txHash.toString()}`, {
+        this.#log.verbose(`Adding tx ${txHash.toString()} to pool`, {
           eventName: 'tx-added-to-pool',
           ...tx.getStats(),
         } satisfies TxAddedToPoolStats);

yarn-project/p2p/src/mem_pools/tx_pool/memory_tx_pool.ts

@@ -105,7 +105,7 @@ export class InMemoryTxPool implements TxPool {
     let pending = 0;
     for (const tx of txs) {
       const txHash = tx.getTxHash();
-      this.log.debug(`Adding tx with id ${txHash.toString()}`, {
+      this.log.verbose(`Adding tx ${txHash.toString()} to pool`, {
         eventName: 'tx-added-to-pool',
         ...tx.getStats(),
       } satisfies TxAddedToPoolStats);

yarn-project/p2p/src/service/peer_manager.ts

@@ -221,7 +221,7 @@ export class PeerManager {
     const id = peer.peerId.toString();
     await this.libP2PNode.peerStore.merge(peer.peerId, { multiaddrs: [peer.multiaddrTcp] });
 
-    this.logger.debug(`Dialing peer ${id}`);
+    this.logger.trace(`Dialing peer ${id}`);
     try {
       await this.libP2PNode.dial(peer.multiaddrTcp);
     } catch (error) {

yarn-project/p2p/src/service/peer_scoring.ts

@@ -82,7 +82,7 @@ export class PeerScoring {
     return this.scores.get(peerId) || 0;
   }
 
-  getStats(): { median: number } {
-    return { median: median(Array.from(this.scores.values())) ?? 0 };
+  getStats(): { medianScore: number } {
+    return { medianScore: median(Array.from(this.scores.values())) ?? 0 };
   }
 }

yarn-project/p2p/src/service/reqresp/reqresp.ts

@@ -196,7 +196,7 @@ export class ReqResp {
     let stream: Stream | undefined;
     try {
       stream = await this.libp2p.dialProtocol(peerId, subProtocol);
-      this.logger.debug(`Stream opened with ${peerId.toString()} for ${subProtocol}`);
+      this.logger.trace(`Stream opened with ${peerId.toString()} for ${subProtocol}`);
 
       // Open the stream with a timeout
       const result = await executeTimeoutWithCustomError<Buffer>(
@@ -206,7 +206,7 @@ export class ReqResp {
       );
 
       await stream.close();
-      this.logger.debug(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
+      this.logger.trace(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
 
       return result;
     } catch (e: any) {
@@ -216,7 +216,7 @@ export class ReqResp {
       if (stream) {
         try {
           await stream.close();
-          this.logger.debug(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
+          this.logger.trace(`Stream closed with ${peerId.toString()} for ${subProtocol}`);
         } catch (closeError) {
           this.logger.error(
             `Error closing stream: ${closeError instanceof Error ? closeError.message : 'Unknown error'}`,

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

@@ -713,7 +713,7 @@ export class Sequencer {
     this.log.debug('Creating block proposal');
     const proposal = await this.validatorClient.createBlockProposal(block.header, block.archive.root, txHashes);
     if (!proposal) {
-      this.log.verbose(`Failed to create block proposal, skipping`);
+      this.log.verbose(`Failed to create block proposal, skipping collecting attestations`);
       return undefined;
     }
 

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

@@ -127,6 +127,16 @@ export class ValidatorClient extends WithTracer implements Validator {
   }
 
   async attestToProposal(proposal: BlockProposal): Promise<BlockAttestation | undefined> {
+    const slotNumber = proposal.slotNumber.toNumber();
+    const proposalInfo = {
+      slotNumber,
+      blockNumber: proposal.payload.header.globalVariables.blockNumber.toNumber(),
+      archive: proposal.payload.archive.toString(),
+      txCount: proposal.payload.txHashes.length,
+      txHashes: proposal.payload.txHashes.map(txHash => txHash.toString()),
+    };
+    this.log.verbose(`Received request to attest for slot ${slotNumber}`);
+
     // Check that I am in the committee
     if (!(await this.epochCache.isInCommittee(this.keyStore.getAddress()))) {
       this.log.verbose(`Not in the committee, skipping attestation`);
@@ -150,10 +160,7 @@ export class ValidatorClient extends WithTracer implements Validator {
     }
 
     // Check that all of the tranasctions in the proposal are available in the tx pool before attesting
-    this.log.verbose(`request to attest`, {
-      archive: proposal.payload.archive.toString(),
-      txHashes: proposal.payload.txHashes.map(txHash => txHash.toString()),
-    });
+    this.log.verbose(`Processing attestation for slot ${slotNumber}`, proposalInfo);
     try {
       await this.ensureTransactionsAreAvailable(proposal);
 
@@ -164,19 +171,17 @@ export class ValidatorClient extends WithTracer implements Validator {
     } catch (error: any) {
       // If the transactions are not available, then we should not attempt to attest
       if (error instanceof TransactionsNotAvailableError) {
-        this.log.error(`Transactions not available, skipping attestation ${error.message}`);
+        this.log.error(`Transactions not available, skipping attestation`, error, proposalInfo);
       } else {
         // This branch most commonly be hit if the transactions are available, but the re-execution fails
         // Catch all error handler
-        this.log.error(`Failed to attest to proposal: ${error.message}`);
+        this.log.error(`Failed to attest to proposal`, error, proposalInfo);
       }
       return undefined;
     }
 
     // Provided all of the above checks pass, we can attest to the proposal
-    this.log.verbose(
-      `Transactions available, attesting to proposal with ${proposal.payload.txHashes.length} transactions`,
-    );
+    this.log.info(`Attesting to proposal for slot ${slotNumber}`, proposalInfo);
 
     // If the above function does not throw an error, then we can attest to the proposal
     return this.validationService.attestToProposal(proposal);
@@ -195,7 +200,6 @@ export class ValidatorClient extends WithTracer implements Validator {
 
     // If we cannot request all of the transactions, then we should fail
     if (txs.length !== txHashes.length) {
-      this.log.error(`Failed to get transactions from the network: ${txHashes.join(', ')}`);
       throw new TransactionsNotAvailableError(txHashes);
     }
 
@@ -209,7 +213,7 @@ export class ValidatorClient extends WithTracer implements Validator {
     const { block } = await this.blockBuilder(txs, header.globalVariables);
     stopTimer();
 
-    this.log.verbose(`Re-ex: Re-execution complete`);
+    this.log.verbose(`Transaction re-execution complete`);
 
     // This function will throw an error if state updates do not match
     if (!block.archive.root.equals(proposal.archive)) {
@@ -240,7 +244,6 @@ export class ValidatorClient extends WithTracer implements Validator {
 
     const requestedTxs = await this.p2pClient.requestTxs(missingTxs);
     if (requestedTxs.some(tx => tx === undefined)) {
-      this.log.error(`Failed to request transactions from the network: ${missingTxs.join(', ')}`);
       throw new TransactionsNotAvailableError(missingTxs);
     }
   }
@@ -267,30 +270,36 @@ export class ValidatorClient extends WithTracer implements Validator {
   ): Promise<BlockAttestation[]> {
     // Wait and poll the p2pClient's attestation pool for this block until we have enough attestations
     const slot = proposal.payload.header.globalVariables.slotNumber.toBigInt();
-    this.log.info(`Waiting for ${numberOfRequiredAttestations} attestations for slot: ${slot}`);
+    this.log.debug(`Collecting ${numberOfRequiredAttestations} attestations for slot ${slot}`);
 
     const proposalId = proposal.archive.toString();
     const myAttestation = await this.validationService.attestToProposal(proposal);
 
     const startTime = Date.now();
 
+    let attestations: BlockAttestation[] = [];
     while (true) {
-      const attestations = [myAttestation, ...(await this.p2pClient.getAttestationsForSlot(slot, proposalId))];
+      const collectedAttestations = [myAttestation, ...(await this.p2pClient.getAttestationsForSlot(slot, proposalId))];
+      const newAttestations = collectedAttestations.filter(
+        collected => !attestations.some(old => old.getSender().equals(collected.getSender())),
+      );
+      for (const attestation of newAttestations) {
+        this.log.debug(`Received attestation for slot ${slot} from ${attestation.getSender().toString()}`);
+      }
+      attestations = collectedAttestations;
 
       if (attestations.length >= numberOfRequiredAttestations) {
-        this.log.info(`Collected all ${numberOfRequiredAttestations} attestations for slot, ${slot}`);
+        this.log.verbose(`Collected all ${numberOfRequiredAttestations} attestations for slot ${slot}`);
         return attestations;
       }
 
       const elapsedTime = Date.now() - startTime;
       if (elapsedTime > this.config.attestationWaitTimeoutMs) {
-        this.log.error(`Timeout waiting for ${numberOfRequiredAttestations} attestations for slot, ${slot}`);
+        this.log.error(`Timeout waiting for ${numberOfRequiredAttestations} attestations for slot ${slot}`);
         throw new AttestationTimeoutError(numberOfRequiredAttestations, slot);
       }
 
-      this.log.verbose(
-        `Collected ${attestations.length} attestations so far, waiting ${this.config.attestationPollingIntervalMs}ms for more...`,
-      );
+      this.log.debug(`Collected ${attestations.length} attestations so far`);
       await sleep(this.config.attestationPollingIntervalMs);
     }
   }