test(e2e): instrument and diagnose bot suite setup cost (#24534)

## What / why

Round-4 e2e speedup, PR 3 of the effort. The `single-node/bot` suite's
file-level `beforeAll` costs
~178s on CI with 97% untagged, and the residual proven-chain waits in
the `private_payments`/`failures`
fees suites (~32s/shard) were also invisible. This PR instruments both
so the cost is attributable, and
diagnoses the bot residual.

Spans are pure passthrough when `TEST_TIMING_FILE` is unset (see
`fixtures/timing.ts`), so this is zero
behavior change for normal runs and CI.

## Commit

- `test(e2e): instrument bot suite setup and fees proven-chain
residuals`
- Bot suite (`single-node/bot/bot.test.ts`): `setup:wallet` around
`EmbeddedWallet.create`,
`wallet:create` around `createSchnorrInitializerlessAccount`, and
`setup:bot` around the four nested
`describe` beforeAll hooks (`Bot.create` / `AmmBot.create` /
`CrossChainBot.create` / `BotStore`).
- Fees harness (`single-node/fees`): `wait:proven-checkpoint` around
`catchUpProvenChain`'s poll loop,
and `warp:proven-checkpoint-epoch` around `advanceToNextEpoch` via a new
instrumented
`FeesTest.advanceToNextEpoch()` wrapper; `waitForEpochProven` and the
direct call sites in
    `failures`/`private_payments` now route through it.
- Reuses existing tags where the concept matches (`wallet:create` is
already what
`createFundedInitializerlessAccounts` fires;
`warp:proven-checkpoint-epoch` is already what
`advanceToNextEpoch` fires in `block-production/setup.ts`) rather than
minting near-duplicates.

## Diagnosis

The timing environment (`shared/timing_env.mjs`) folds *every*
`beforeAll` in a file — the file-level
one plus each nested `describe`'s — into a single suite-scoped
`beforeHooksMs`, and every span fired
during any beforeAll lands on that same suite line. The shortlist read
the whole number as the
file-level hook and, seeing only `setup:env:*` tagged, attributed the
rest to the one visible untagged
file-level call (`createSchnorrInitializerlessAccount`). It is actually
the nested hooks.

Local read (`TEST_TIMING_SPANS=1`, `PIPELINING_SETUP_OPTS` = 12s L2
slots, production sequencer, fake
prover), suite `beforeHooksMs = 153,733 ms`:

- `setup:env:*` (file-level `setup()`): ~4.6s — already tagged
- `setup:wallet` (`EmbeddedWallet.create`, ephemeral): **137 ms** — the
PXE has `autoSync:false`, no
  genesis walk
- `wallet:create` (`createSchnorrInitializerlessAccount`): **69 ms** —
initializerless, no deploy tx, as
  designed
- `setup:bot` (4 nested hooks): **149,582 ms = 97.3%** of the file's
beforeAll
- transaction-bot `Bot.create`: 32.2s (token deploy class+instance, then
private+public mint)
  - bridge-resume `new BotStore(...)`: 0.9 ms
- amm-bot `AmmBot.create`: 73.9s (deploys 4 contracts + set_minter +
mint + add_liquidity)
- cross-chain-bot `CrossChainBot.create`: 43.5s (TestContract deploy +
seed 2 L1→L2 msgs + wait ready)

**Root cause: structural, not a bug.** The bot suite runs the production
Sequencer to exercise
CHECKPOINTED/PROPOSED follow modes and L1 fee-juice bridging, so each
`Bot.create` deploys real
contracts and mints serially at slot cadence (`bot/src/factory.ts`). The
two calls the shortlist
suspected are ~0.1s each.

No fix is shipped here because there is no safe one-liner: speeding this
up means batching/parallelizing
the `bot/src/factory.ts` deploy/mint paths (production code,
PR-6-shaped), genesis-seeding (PR 1/2), or
cutting the CI slot time (PR 5) — none belong in the instrumentation PR.
Tracked as a round-5 item; the
new `setup:bot` span makes that win measurable. Full write-up in
`tmp/SPEEDUP_ROUND4_FINDINGS.md`.

## Expected effect

No wall-clock change (passthrough spans). The deliverable is visibility:
the previously-invisible
`setup:bot` / `setup:wallet` / `wallet:create` decomposition of the bot
beforeAll, and the
`wait:proven-checkpoint` / `warp:proven-checkpoint-epoch` residual in
the fees suites.

Measured numbers from a full green CI run will be appended below once
available.


## Measured impact

Both runs are full CI runs. PR run: `ci/x-fast` on head `1f7898cd2b` (CI
1783345614459429, 1,799 test
lines). Baseline: `ci/x-full-no-test-cache` on the exact merge-base
`a8cfa93df5` (CI 1783341726388943,
1,863 test lines). No wall-clock change claimed (spans are passthrough;
suite-level noise floor is
~11s median / ~52s p90) — the deliverable is attribution, measured as
span `busyMs`.

Bot suite (`suite` line, beforeAll = 181.5s on the PR run vs 182.1s
baseline):

- Baseline: 7.4s tagged (`setup:env:*` only) → **174.8s / 96%
invisible**.
- PR run: `setup:bot` **174,203 ms** (4 occurrences, max 86,961 ms = the
amm-bot hook),
`setup:wallet` **250 ms**, `wallet:create` **144 ms**; residual now
**−1.5s ≈ 0** →
  **100% of the beforeAll is attributed**.
- This confirms the diagnosis: `EmbeddedWallet.create` +
`createSchnorrInitializerlessAccount` are
~0.4s combined; the "invisible 178s" is the four nested describes'
bot-factory setup
(deploys + mints at production 12s-slot cadence), folded into the file's
suite line by the
  hook accounting.

Fees suites (`private_payments.parallel` × 8 shards + `failures`):

- Baseline: avg **32.3s/shard untagged residual** (zero
`wait:proven-checkpoint` /
  `warp:proven-checkpoint-epoch` lines on these suites).
- PR run: `wait:proven-checkpoint` fires on all 9 suite hooks, **293,888
ms total**
(avg 32.7s/shard — matches the residual exactly), plus one in-test
occurrence (32.1s);
`warp:proven-checkpoint-epoch` 19 occurrences, 361 ms total (the warp
RPC itself is
near-free — the cost is entirely the proven-chain poll that follows).
Per-shard residual is now
  ≈ −1s, i.e. fully attributed.

Net: **~469s/run of previously invisible setup/wait cost is now tagged
and attributable**
(174.2s `setup:bot` + 0.4s wallet spans + 294.3s fees proven-chain
waits), with no behavior or
wall-clock change.


Fixes A-1407

Author: spalladino

yarn-project/end-to-end/src/single-node/bot/bot.test.ts

@@ -22,6 +22,7 @@ import { EmbeddedWallet } from '@aztec/wallets/embedded';
 import { jest } from '@jest/globals';
 
 import { PIPELINED_FEE_PADDING, PIPELINING_SETUP_OPTS } from '../../fixtures/fixtures.js';
+import { testSpan } from '../../fixtures/timing.js';
 import { getPrivateKeyFromIndex, setup } from '../../fixtures/utils.js';
 import { NO_REORG_SUBMISSION_EPOCHS } from '../setup.js';
 
@@ -54,8 +55,10 @@ describe('single-node/bot/bot', () => {
       cheatCodes,
       config: { l1RpcUrls },
     } = setupResult);
-    wallet = await EmbeddedWallet.create(aztecNode, { ephemeral: true });
-    await wallet.createSchnorrInitializerlessAccount(botAccount.secret, botAccount.salt, botAccount.signingKey);
+    wallet = await testSpan('setup:wallet', () => EmbeddedWallet.create(aztecNode, { ephemeral: true }));
+    await testSpan('wallet:create', () =>
+      wallet.createSchnorrInitializerlessAccount(botAccount.secret, botAccount.salt, botAccount.signingKey),
+    );
   });
 
   afterAll(() => teardown());
@@ -73,7 +76,9 @@ describe('single-node/bot/bot', () => {
         botMode: 'transfer',
         minFeePadding: PIPELINED_FEE_PADDING,
       };
-      bot = await Bot.create(config, wallet, aztecNode, undefined, new BotStore(await openTmpStore('bot')));
+      bot = await testSpan('setup:bot', async () =>
+        Bot.create(config, wallet, aztecNode, undefined, new BotStore(await openTmpStore('bot'))),
+      );
     });
 
     // Runs bot.run() once and asserts recipient private and public balances each increase by 1.
@@ -131,7 +136,7 @@ describe('single-node/bot/bot', () => {
     let store: BotStore;
 
     beforeAll(async () => {
-      store = new BotStore(await openTmpStore('bot'));
+      store = await testSpan('setup:bot', async () => new BotStore(await openTmpStore('bot')));
     });
 
     afterAll(async () => {
@@ -238,7 +243,9 @@ describe('single-node/bot/bot', () => {
         followChain: 'CHECKPOINTED',
         botMode: 'amm',
       };
-      bot = await AmmBot.create(config, wallet, aztecNode, undefined, new BotStore(await openTmpStore('bot')));
+      bot = await testSpan('setup:bot', async () =>
+        AmmBot.create(config, wallet, aztecNode, undefined, new BotStore(await openTmpStore('bot'))),
+      );
     });
 
     // Runs the AMM bot once and asserts one of the two private token balances decreased and
@@ -302,12 +309,8 @@ describe('single-node/bot/bot', () => {
         flushSetupTransactions: true,
         l1ToL2SeedCount: 2,
       };
-      bot = await CrossChainBot.create(
-        config,
-        wallet,
-        aztecNode,
-        aztecNodeAdmin,
-        new BotStore(await openTmpStore('bot')),
+      bot = await testSpan('setup:bot', async () =>
+        CrossChainBot.create(config, wallet, aztecNode, aztecNodeAdmin, new BotStore(await openTmpStore('bot'))),
       );
     }, 600_000);
 

yarn-project/end-to-end/src/single-node/fees/failures.test.ts

@@ -57,7 +57,7 @@ describe('single-node/fees/failures', () => {
     aztecNode = t.aztecNode;
 
     // Prove up until the current state by advancing the epoch and waiting for the prover node.
-    await t.cheatCodes.rollup.advanceToNextEpoch();
+    await t.advanceToNextEpoch();
     await t.catchUpProvenChain();
   });
 
@@ -123,7 +123,7 @@ describe('single-node/fees/failures', () => {
 
     // @note There is a potential race condition here if other tests send transactions that get into the same
     // epoch and thereby pays out fees at the same time (when proven).
-    await t.cheatCodes.rollup.advanceToNextEpoch();
+    await t.advanceToNextEpoch();
     const provenTimeout =
       (t.context.config.aztecProofSubmissionEpochs + 1) *
       t.context.config.aztecEpochDuration *
@@ -362,7 +362,7 @@ describe('single-node/fees/failures', () => {
     );
 
     // Prove the block containing the teardown-reverted tx (revert_code = 2).
-    await t.cheatCodes.rollup.advanceToNextEpoch();
+    await t.advanceToNextEpoch();
     const provenTimeout =
       (t.context.config.aztecProofSubmissionEpochs + 1) *
       t.context.config.aztecEpochDuration *
@@ -389,7 +389,7 @@ describe('single-node/fees/failures', () => {
     expect(receipt.executionResult).toBe(TxExecutionResult.REVERTED);
     expect(receipt.transactionFee).toBeGreaterThan(0n);
 
-    await t.cheatCodes.rollup.advanceToNextEpoch();
+    await t.advanceToNextEpoch();
     const provenTimeout =
       (t.context.config.aztecProofSubmissionEpochs + 1) *
       t.context.config.aztecEpochDuration *

yarn-project/end-to-end/src/single-node/fees/fees_test.ts

@@ -131,15 +131,22 @@ export class FeesTest extends SingleNodeTestContext {
   }
 
   async catchUpProvenChain() {
-    const bn = await this.aztecNode.getBlockNumber();
-    while ((await this.aztecNode.getBlockNumber('proven')) < bn) {
-      await sleep(1000);
-    }
+    await testSpan('wait:proven-checkpoint', async () => {
+      const bn = await this.aztecNode.getBlockNumber();
+      while ((await this.aztecNode.getBlockNumber('proven')) < bn) {
+        await sleep(1000);
+      }
+    });
+  }
+
+  /** Warps L1 to the next epoch boundary so the current epoch closes and can be proven. */
+  async advanceToNextEpoch() {
+    await testSpan('warp:proven-checkpoint-epoch', () => this.cheatCodes.rollup.advanceToNextEpoch());
   }
 
   /** Advances to the next epoch and waits for the proven chain to catch up, so all prior fees are paid out. */
   async waitForEpochProven() {
-    await this.cheatCodes.rollup.advanceToNextEpoch();
+    await this.advanceToNextEpoch();
     await this.catchUpProvenChain();
   }
 

yarn-project/end-to-end/src/single-node/fees/private_payments.parallel.test.ts

@@ -140,7 +140,7 @@ describe('single-node/fees/private_payments', () => {
     const provenCheckpointBefore = await t.rollupContract.getProvenCheckpointNumber();
 
     const receipt = await localTx.send({ timeout: 300, interval: 10 });
-    await t.cheatCodes.rollup.advanceToNextEpoch();
+    await t.advanceToNextEpoch();
 
     await waitForProven(aztecNode, receipt, { provenTimeout: 300 });