Extra logging and test fix

Author: spalladino

yarn-project/archiver/src/archiver/archiver.test.ts

@@ -397,10 +397,20 @@ describe('Archiver', () => {
 
     // And define a bad block 2 with attestations from random signers
     const badBlock2 = await makeBlock(2);
+    badBlock2.archive.root = new Fr(0x1002);
     const badBlock2RollupTx = await makeRollupTx(badBlock2, times(3, Secp256k1Signer.random));
     const badBlock2BlobHashes = await makeVersionedBlobHashes(badBlock2);
     const badBlock2Blobs = await makeBlobsFromBlock(badBlock2);
 
+    // Return the archive root for the bad block 2 when queried
+    mockRollupRead.archiveAt.mockImplementation((args: readonly [bigint]) =>
+      Promise.resolve((args[0] === 2n ? badBlock2 : blocks[Number(args[0] - 1n)]).archive.root.toString()),
+    );
+
+    logger.warn(`Created 3 valid blocks`);
+    blocks.forEach(block => logger.warn(`Block ${block.number} with root ${block.archive.root.toString()}`));
+    logger.warn(`Created invalid block 2 with root ${badBlock2.archive.root.toString()}`);
+
     // During the first archiver loop, we fetch block 1 and the block 2 with bad attestations
     publicClient.getBlockNumber.mockResolvedValue(85n);
     makeL2BlockProposedEvent(70n, 1n, blocks[0].archive.root.toString(), blobHashes[0]);
@@ -429,6 +439,9 @@ describe('Archiver', () => {
     ]);
     publicClient.getTransaction.mockResolvedValueOnce(rollupTxs[1]).mockResolvedValueOnce(rollupTxs[2]);
     blobSinkClient.getBlobSidecar.mockResolvedValueOnce(blobsFromBlocks[1]).mockResolvedValueOnce(blobsFromBlocks[2]);
+    mockRollupRead.archiveAt.mockImplementation((args: readonly [bigint]) =>
+      Promise.resolve(blocks[Number(args[0] - 1n)].archive.root.toString()),
+    );
 
     // Now we should move to block 3
     await waitUntilArchiverBlock(3);
@@ -534,7 +547,7 @@ describe('Archiver', () => {
     // Lets take a look to see if we can find re-org stuff!
     await sleep(2000);
 
-    expect(loggerSpy).toHaveBeenCalledWith(`L2 prune has been detected.`);
+    expect(loggerSpy).toHaveBeenCalledWith(expect.stringContaining(`L2 prune has been detected`), expect.anything());
 
     // Should also see the block number be reduced
     latestBlockNum = await archiver.getBlockNumber();

yarn-project/archiver/src/archiver/archiver.ts

@@ -703,7 +703,8 @@ export class Archiver extends (EventEmitter as new () => ArchiverEmitter) implem
         throw new Error(`Missing block ${localPendingBlockNumber}`);
       }
 
-      const noBlockSinceLast = localPendingBlock && pendingArchive === localPendingBlock.archive.root.toString();
+      const localPendingArchiveRoot = localPendingBlock.archive.root.toString();
+      const noBlockSinceLast = localPendingBlock && pendingArchive === localPendingArchiveRoot;
       if (noBlockSinceLast) {
         // We believe the following line causes a problem when we encounter L1 re-orgs.
         // Basically, by setting the synched L1 block number here, we are saying that we have
@@ -717,13 +718,16 @@ export class Archiver extends (EventEmitter as new () => ArchiverEmitter) implem
         return rollupStatus;
       }
 
-      const localPendingBlockInChain = archiveForLocalPendingBlockNumber === localPendingBlock.archive.root.toString();
+      const localPendingBlockInChain = archiveForLocalPendingBlockNumber === localPendingArchiveRoot;
       if (!localPendingBlockInChain) {
         // If our local pending block tip is not in the chain on L1 a "prune" must have happened
         // or the L1 have reorged.
         // In any case, we have to figure out how far into the past the action will take us.
         // For simplicity here, we will simply rewind until we end in a block that is also on the chain on L1.
-        this.log.debug(`L2 prune has been detected.`);
+        this.log.debug(
+          `L2 prune has been detected due to local pending block ${localPendingBlockNumber} not in chain`,
+          { localPendingBlockNumber, localPendingArchiveRoot, archiveForLocalPendingBlockNumber },
+        );
 
         let tipAfterUnwind = localPendingBlockNumber;
         while (true) {

yarn-project/archiver/src/archiver/validation.ts

@@ -15,23 +15,24 @@ export async function validateBlockAttestations(
 ): Promise<boolean> {
   const attestations = getAttestationsFromPublishedL2Block(publishedBlock);
   const { block } = publishedBlock;
+  const blockHash = await block.hash().then(hash => hash.toString());
+  const archiveRoot = block.archive.root.toString();
   const slot = block.header.getSlot();
   const epoch = getEpochAtSlot(slot, constants);
   const { committee } = await epochCache.getCommitteeForEpoch(epoch);
-  logger?.debug(`Validating attestations for block at slot ${slot} in epoch ${epoch}`, {
+  const logData = { blockNumber: block.number, slot, epoch, blockHash, archiveRoot };
+  logger?.debug(`Validating attestations for block ${block.number} at slot ${slot} in epoch ${epoch}`, {
     committee: (committee ?? []).map(member => member.toString()),
     recoveredAttestors: attestations.map(a => a.getSender().toString()),
     postedAttestations: publishedBlock.attestations.map(a =>
       a.address.isZero() ? a.signature.toString() : a.address.toString(),
     ),
-    blockNumber: block.number,
-    slot,
-    epoch,
+    ...logData,
   });
 
   if (!committee || committee.length === 0) {
     // Q: Should we accept blocks with no committee?
-    logger?.warn(`No committee found for epoch ${epoch} at slot ${slot}`);
+    logger?.warn(`No committee found for epoch ${epoch} at slot ${slot}. Accepting block without validation.`, logData);
     return true;
   }
 
@@ -50,14 +51,11 @@ export async function validateBlockAttestations(
     logger?.warn(`Insufficient attestations for block at slot ${slot}`, {
       requiredAttestations: requiredAttestationCount,
       actualAttestations: attestations.length,
+      ...logData,
     });
     return false;
   }
 
-  logger?.debug(`Block attestations validated successfully for block at slot ${slot}`, {
-    blockNumber: block.number,
-    slot,
-    epoch,
-  });
+  logger?.debug(`Block attestations validated successfully for block ${block.number} at slot ${slot}`, logData);
   return true;
 }