Sim tests refactoring

packages/cli/test/sim/eip4844.test.ts

@@ -17,7 +17,7 @@ const additionalSlotsForTTD = activePreset.SLOTS_PER_EPOCH - 2;
 const runTillEpoch = 6;
 const syncWaitEpoch = 2;
 
-const timeout =
+const runTimeoutMs =
   getEstimatedTimeInSecForRun({
     genesisSlotDelay: genesisSlotsDelay,
     secondsPerSlot: SIM_TESTS_SECONDS_PER_SLOT,
@@ -58,7 +58,7 @@ env.tracker.register({
   },
 });
 
-await env.start(timeout);
+await env.start({runTimeoutMs});
 await connectAllNodes(env.nodes);
 
 // The `TTD` will be reach around `start of bellatrixForkEpoch + additionalSlotsForMerge` slot

packages/cli/test/sim/endpoints.test.ts

@@ -13,7 +13,7 @@ const genesisSlotsDelay = 10;
 const altairForkEpoch = 2;
 const bellatrixForkEpoch = 4;
 const validatorCount = 2;
-const timeout =
+const runTimeoutMs =
   getEstimatedTimeInSecForRun({
     genesisSlotDelay: genesisSlotsDelay,
     secondsPerSlot: SIM_TESTS_SECONDS_PER_SLOT,
@@ -42,7 +42,7 @@ const env = SimulationEnvironment.initWithDefaults(
     },
   ]
 );
-await env.start(timeout);
+await env.start({runTimeoutMs});
 
 const node = env.nodes[0].cl;
 await waitForSlot(2, env.nodes, {env, silent: true});

packages/cli/test/sim/multi_fork.test.ts

@@ -24,7 +24,7 @@ const additionalSlotsForTTD = activePreset.SLOTS_PER_EPOCH - 2;
 const runTillEpoch = 6;
 const syncWaitEpoch = 2;
 
-const timeout =
+const runTimeoutMs =
   getEstimatedTimeInSecForRun({
     genesisSlotDelay: genesisSlotsDelay,
     secondsPerSlot: SIM_TESTS_SECONDS_PER_SLOT,
@@ -75,7 +75,7 @@ env.tracker.register({
   },
 });
 
-await env.start(timeout);
+await env.start({runTimeoutMs});
 await connectAllNodes(env.nodes);
 
 // The `TTD` will be reach around `start of bellatrixForkEpoch + additionalSlotsForMerge` slot

packages/cli/test/utils/simulation/EpochClock.ts

@@ -65,6 +65,10 @@ export class EpochClock {
     return this.genesisTime + slotGenesisTimeOffset;
   }
 
+  msToGenesis(): number {
+    return this.genesisTime * 1000 - Date.now();
+  }
+
   isFirstSlotOfEpoch(slot: number): boolean {
     return slot % this.slotsPerEpoch === 0;
   }

packages/cli/test/utils/simulation/SimulationEnvironment.ts

@@ -17,6 +17,8 @@ import {
   EL_ETH_BASE_PORT,
   EL_P2P_BASE_PORT,
   KEY_MANAGER_BASE_PORT,
+  MOCK_ETH1_GENESIS_HASH,
+  SHARED_JWT_SECRET,
   SIM_TESTS_SECONDS_PER_SLOT,
 } from "./constants.js";
 import {generateGethNode} from "./el_clients/geth.js";
@@ -48,7 +50,9 @@ import {DockerRunner} from "./runner/DockerRunner.js";
 import {SimulationTracker} from "./SimulationTracker.js";
 import {getEstimatedTTD} from "./utils/index.js";
 
-export const SHARED_JWT_SECRET = "0xdc6457099f127cf0bac78de8b297df04951281909db4f58b43def7c7151e765d";
+interface StartOpts {
+  runTimeoutMs: number;
+}
 
 /* eslint-disable no-console */
 
@@ -136,12 +140,19 @@ export class SimulationEnvironment {
     return env;
   }
 
-  async start(timeout: number): Promise<void> {
-    try {
-      setTimeout(async () => {
-        await this.stop(1, "On timeout");
-      }, timeout);
+  async start(opts: StartOpts): Promise<void> {
+    setTimeout(() => {
+      this.stop(1, `Sim run timedout in ${opts.runTimeoutMs} ms `).catch((e) => console.error("Error on stop", e));
+    }, opts.runTimeoutMs);
+
+    const msToGenesis = this.clock.msToGenesis();
+    const startTimeout = setTimeout(() => {
+      this.stop(1, `Start sequence not completed before genesis, in ${msToGenesis} ms`).catch((e) =>
+        console.error("Error on stop", e)
+      );
+    }, msToGenesis);
 
+    try {
       process.on("unhandledRejection", async (reason, promise) => {
         console.error("Unhandled Rejection at:", promise, "reason:", reason);
         await this.stop(1, "Unhandled promise rejection");
@@ -169,7 +180,8 @@ export class SimulationEnvironment {
         const el = this.nodes[i].el;
 
         // If eth1 is mock then genesis hash would be empty
-        const eth1Genesis = el.provider === null ? {hash: ""} : await el.provider.getBlockByNumber(0);
+        const eth1Genesis =
+          el.provider === null ? {hash: MOCK_ETH1_GENESIS_HASH} : await el.provider.getBlockByNumber(0);
 
         if (!eth1Genesis) {
           throw new Error(`Eth1 genesis not found for node "${this.nodes[i].id}"`);
@@ -191,19 +203,28 @@ export class SimulationEnvironment {
 
       await Promise.all(this.jobs.map((j) => j.cl.start()));
 
-      await this.externalSigner.start();
-      for (const node of this.nodes) {
-        const remoteKeys = node.cl.remoteKeys;
-        this.externalSigner.addKeys(remoteKeys);
-        await node.cl.keyManager.importRemoteKeys(
-          remoteKeys.map((sk) => ({pubkey: sk.toPublicKey().toHex(), url: this.externalSigner.url}))
-        );
+      if (this.nodes.some((node) => node.cl.keys.type === "remote")) {
+        console.log("Starting external signer...");
+        await this.externalSigner.start();
+        console.log("Started external signer");
+
+        for (const node of this.nodes) {
+          if (node.cl.keys.type === "remote") {
+            this.externalSigner.addKeys(node.cl.keys.secretKeys);
+            await node.cl.keyManager.importRemoteKeys(
+              node.cl.keys.secretKeys.map((sk) => ({pubkey: sk.toPublicKey().toHex(), url: this.externalSigner.url}))
+            );
+            console.log(`Imported remote keys for node ${node.id}`);
+          }
+        }
       }
 
       await this.tracker.start();
       await Promise.all(this.nodes.map((node) => this.tracker.track(node)));
     } catch (error) {
-      await this.stop(1, `Caused error in startup. ${(error as Error).message}`);
+      await this.stop(1, `Error in startup. ${(error as Error).stack}`);
+    } finally {
+      clearTimeout(startTimeout);
     }
   }
 
@@ -249,8 +270,12 @@ export class SimulationEnvironment {
 
     const clClient = this.createCLNode(cl, {
       id,
-      remoteKeys: remote ? keys : [],
-      localKeys: remote ? [] : keys,
+      keys:
+        keys.length > 0 && remote
+          ? {type: "remote", secretKeys: keys}
+          : keys.length > 0
+          ? {type: "local", secretKeys: keys}
+          : {type: "no-keys"},
       engineMock: typeof el === "string" ? el === ELClient.Mock : el.type === ELClient.Mock,
     });
 
@@ -264,7 +289,7 @@ export class SimulationEnvironment {
 
   private createCLNode<C extends CLClient>(
     client: C | {type: C; options: CLClientsOptions[C]},
-    options?: AtLeast<CLClientGeneratorOptions, "remoteKeys" | "localKeys" | "id">
+    options?: AtLeast<CLClientGeneratorOptions, "keys" | "id">
   ): {job: Job; node: CLNode} {
     const clientType = typeof client === "object" ? client.type : client;
     const clientOptions = typeof client === "object" ? client.options : undefined;
@@ -283,8 +308,7 @@ export class SimulationEnvironment {
           keyManagerPort: KEY_MANAGER_BASE_PORT + this.nodePairCount + 1,
           config: this.forkConfig,
           address: "127.0.0.1",
-          remoteKeys: options?.remoteKeys ?? [],
-          localKeys: options?.localKeys ?? [],
+          keys: options?.keys ?? {type: "no-keys"},
           genesisTime: this.options.genesisTime,
           engineUrl: options?.engineUrl ?? `http://127.0.0.1:${EL_ENGINE_BASE_PORT + this.nodePairCount + 1}`,
           engineMock: options?.engineMock ?? false,

packages/cli/test/utils/simulation/SimulationTracker.ts

@@ -135,12 +135,28 @@ export class SimulationTracker {
       this.initEventStreamForNode(node);
     }
     this.reporter.bootstrap();
+
+    // Start clock loop on current slot or genesis
+    this.clockLoop(Math.max(this.clock.currentSlot, 0)).catch((e) => {
+      console.error("error on clockLoop", e);
+    });
   }
 
   async stop(): Promise<void> {
     // Do nothing;
   }
 
+  async clockLoop(slot: number): Promise<void> {
+    while (!this.signal.aborted) {
+      // Wait for 2/3 of the slot to consider it missed
+      await this.clock.waitForStartOfSlot(slot + 2 / 3).catch((e) => {
+        console.error("error on waitForStartOfSlot", e);
+      });
+      this.reporter.progress(slot);
+      slot++;
+    }
+  }
+
   getErrorCount(): number {
     return this.errors.length;
   }

packages/cli/test/utils/simulation/TableRenderer.ts

@@ -1,3 +1,5 @@
+import {strFixedSize} from "./utils/index.js";
+
 export class TableRenderer<Columns extends string[number]> {
   private columnsSizes: Record<Columns, number>;
   private columns: Columns[];
@@ -20,7 +22,7 @@ export class TableRenderer<Columns extends string[number]> {
   addEmptyRow(text: string): void {
     this.printHSeparator(true);
     this.printVSeparator("start");
-    process.stdout.write(text.padEnd(this.totalWidth - 4));
+    process.stdout.write(strFixedSize(text, this.totalWidth - 4));
     this.printVSeparator("end");
     this.printHSeparator(true);
   }
@@ -29,7 +31,7 @@ export class TableRenderer<Columns extends string[number]> {
     this.printHSeparator(true);
     this.printVSeparator("start");
     for (const [index, column] of this.columns.entries()) {
-      process.stdout.write(column.padEnd(this.columnsSizes[column]));
+      process.stdout.write(strFixedSize(column, this.columnsSizes[column]));
       if (index === this.columns.length - 1) {
         this.printVSeparator("end");
       } else {

packages/cli/test/utils/simulation/TableReporter.ts

@@ -6,6 +6,8 @@ import {TableRenderer} from "./TableRenderer.js";
 import {arrayGroupBy, avg} from "./utils/index.js";
 
 export class TableReporter extends SimulationReporter<typeof defaultAssertions> {
+  private lastPrintedSlot = -1;
+
   private table = new TableRenderer({
     fork: 10,
     eph: 5,
@@ -23,73 +25,79 @@ export class TableReporter extends SimulationReporter<typeof defaultAssertions>
   }
 
   progress(slot: Slot): void {
-    {
-      const {clock, forkConfig, nodes, stores, errors} = this.options;
-
-      const epoch = clock.getEpochForSlot(slot);
-      const forkName = forkConfig.getForkName(slot);
-      const epochStr = `${epoch}/${clock.getSlotIndexInEpoch(slot)}`;
-
-      if (clock.isFirstSlotOfEpoch(slot)) {
-        // We are printing this info for last epoch
-        if (epoch - 1 < forkConfig.ALTAIR_FORK_EPOCH) {
-          this.table.addEmptyRow("Att Participation: N/A - SC Participation: N/A");
-        } else {
-          // attestationParticipation is calculated at first slot of an epoch
-          const participation = nodes.map((node) => stores["attestationParticipation"][node.cl.id][slot] ?? 0);
-          const head = avg(participation.map((p) => p.head)).toFixed(2);
-          const source = avg(participation.map((p) => p.source)).toFixed(2);
-          const target = avg(participation.map((p) => p.target)).toFixed(2);
-
-          // As it's printed on the first slot of epoch we need to get the previous epoch
-          const startSlot = clock.getFirstSlotOfEpoch(epoch - 1);
-          const endSlot = clock.getLastSlotOfEpoch(epoch - 1);
-          const nodesSyncParticipationAvg: number[] = [];
-          for (const node of nodes) {
-            const syncCommitteeParticipation: number[] = [];
-            for (let slot = startSlot; slot <= endSlot; slot++) {
-              syncCommitteeParticipation.push(stores["syncCommitteeParticipation"][node.cl.id][slot]);
-            }
-            nodesSyncParticipationAvg.push(avg(syncCommitteeParticipation));
+    // Print slots once, may be called twice for missed block timer
+    if (slot <= this.lastPrintedSlot) {
+      return;
+    } else {
+      this.lastPrintedSlot = slot;
+    }
+
+    const {clock, forkConfig, nodes, stores, errors} = this.options;
+
+    const epoch = clock.getEpochForSlot(slot);
+    const forkName = forkConfig.getForkName(slot);
+    const epochStr = `${epoch}/${clock.getSlotIndexInEpoch(slot)}`;
+
+    if (clock.isFirstSlotOfEpoch(slot)) {
+      // We are printing this info for last epoch
+      if (epoch - 1 < forkConfig.ALTAIR_FORK_EPOCH) {
+        this.table.addEmptyRow("Att Participation: N/A - SC Participation: N/A");
+      } else {
+        // attestationParticipation is calculated at first slot of an epoch
+        const participation = nodes.map((node) => stores["attestationParticipation"][node.cl.id][slot] ?? 0);
+        const head = avg(participation.map((p) => p.head)).toFixed(2);
+        const source = avg(participation.map((p) => p.source)).toFixed(2);
+        const target = avg(participation.map((p) => p.target)).toFixed(2);
+
+        // As it's printed on the first slot of epoch we need to get the previous epoch
+        const startSlot = clock.getFirstSlotOfEpoch(epoch - 1);
+        const endSlot = clock.getLastSlotOfEpoch(epoch - 1);
+        const nodesSyncParticipationAvg: number[] = [];
+        for (const node of nodes) {
+          const syncCommitteeParticipation: number[] = [];
+          for (let slot = startSlot; slot <= endSlot; slot++) {
+            syncCommitteeParticipation.push(stores["syncCommitteeParticipation"][node.cl.id][slot]);
           }
+          nodesSyncParticipationAvg.push(avg(syncCommitteeParticipation));
+        }
 
-          const syncParticipation = avg(nodesSyncParticipationAvg).toFixed(2);
+        const syncParticipation = avg(nodesSyncParticipationAvg).toFixed(2);
 
-          this.table.addEmptyRow(
-            `Att Participation: H: ${head}, S: ${source}, T: ${target} - SC Participation: ${syncParticipation}`
-          );
-        }
+        this.table.addEmptyRow(
+          `Att Participation: H: ${head}, S: ${source}, T: ${target} - SC Participation: ${syncParticipation}`
+        );
       }
+    }
 
-      const finalizedSlots = nodes.map((node) => stores["finalized"][node.cl.id][slot] ?? "-");
-      const finalizedSlotsUnique = new Set(finalizedSlots);
+    const finalizedSlots = nodes.map((node) => stores["finalized"][node.cl.id][slot] ?? "-");
+    const finalizedSlotsUnique = new Set(finalizedSlots);
 
-      const inclusionDelay = nodes.map((node) => stores["inclusionDelay"][node.cl.id][slot] ?? "-");
-      const inclusionDelayUnique = new Set(inclusionDelay);
+    const inclusionDelay = nodes.map((node) => stores["inclusionDelay"][node.cl.id][slot] ?? "-");
+    const inclusionDelayUnique = new Set(inclusionDelay);
 
-      const attestationCount = nodes.map((node) => stores["attestationsCount"][node.cl.id][slot] ?? "-");
-      const attestationCountUnique = new Set(attestationCount);
+    const attestationCount = nodes.map((node) => stores["attestationsCount"][node.cl.id][slot] ?? "-");
+    const attestationCountUnique = new Set(attestationCount);
 
-      const head = nodes.map((node) => stores["head"][node.cl.id][slot] ?? "-");
-      const headUnique = new Set(head);
+    const heads = nodes.map((node) => stores["head"][node.cl.id][slot]);
+    const head0 = heads.length > 0 ? heads[0] : null;
+    const nodesHaveSameHead = heads.every((head) => head?.blockRoot !== head0?.blockRoot);
 
-      const peerCount = nodes.map((node) => stores["connectedPeerCount"][node.cl.id][slot] ?? "-");
-      const peerCountUnique = new Set(head);
+    const peerCount = nodes.map((node) => stores["connectedPeerCount"][node.cl.id][slot] ?? "-");
+    const peerCountUnique = new Set(peerCount);
 
-      const errorCount = errors.filter((e) => e.slot === slot).length;
+    const errorCount = errors.filter((e) => e.slot === slot).length;
 
-      this.table.addRow({
-        fork: forkName,
-        eph: epochStr,
-        slot: slot,
-        head: headUnique.size === 1 ? `${head[0].slice(0, 6)}..` : "different",
-        finzed: finalizedSlotsUnique.size === 1 ? finalizedSlots[0] : finalizedSlots.join(","),
-        peers: peerCountUnique.size === 1 ? peerCount[0] : peerCount.join(","),
-        attCount: attestationCountUnique.size === 1 ? attestationCount[0] : "---",
-        incDelay: inclusionDelayUnique.size === 1 ? inclusionDelay[0].toFixed(2) : "---",
-        errors: errorCount,
-      });
-    }
+    this.table.addRow({
+      fork: forkName,
+      eph: epochStr,
+      slot: head0 ? head0.slot : "-",
+      head: head0 ? (nodesHaveSameHead ? `${head0?.blockRoot.slice(0, 6)}..` : "different") : "-",
+      finzed: finalizedSlotsUnique.size === 1 ? finalizedSlots[0] : finalizedSlots.join(","),
+      peers: peerCountUnique.size === 1 ? peerCount[0] : peerCount.join(","),
+      attCount: attestationCountUnique.size === 1 ? attestationCount[0] : "---",
+      incDelay: inclusionDelayUnique.size === 1 ? inclusionDelay[0].toFixed(2) : "---",
+      errors: errorCount,
+    });
   }
 
   summary(): void {