From ba28788de22b3209ec324633e91875b3b4b86332 Mon Sep 17 00:00:00 2001 From: Santiago Palladino Date: Tue, 17 Dec 2024 19:14:54 -0300 Subject: [PATCH] fix: Try fix e2e epochs in CI (#10804) Attempts two fixes at e2e epochs test. First, it increases the L1 block time, to account for general CI slowness. Second, it adds more retries to the L1 gas utils getTx, since the e2e epochs test works using the tx delayer, which artificially introduces a delay between a tx being sent and it being available in anvil, so it triggered a timeout in the utils. **Update**: Increasing the retries caused the error to change, we were getting a timeout in teardown. This was caused because the sequencer got stuck in waiting for the tx to be mined for way too long (more than 5 minutes, the afterAll hook timeout), and the `node.stop()` waits for the current loops to end before returning. But what's interesting is _why_ the sequencer got stuck in waiting for its tx to be mined. The tx was being delayed by the tx-delayer, which intercepts txs, manually computes their tx hash to return it to the caller immediately, and holds on the tx to submit it to anvil at a later point in time. What came up is that the tx hash we were manually computing over txs with blobs did not match the tx hash returned by anvil. This has been logged as #10824. However, we can sidestep this issue by just choosing a reasonable value for max attempts so teardown doesn't timeout. --------- Co-authored-by: ludamad --- .../end-to-end/src/e2e_epochs.test.ts | 34 +++++++++++-------- yarn-project/ethereum/src/l1_tx_utils.ts | 17 ++++++++-- yarn-project/ethereum/src/test/tx_delayer.ts | 20 ++++++++--- yarn-project/foundation/src/config/env_var.ts | 1 + 4 files changed, 52 insertions(+), 20 deletions(-) diff --git a/yarn-project/end-to-end/src/e2e_epochs.test.ts b/yarn-project/end-to-end/src/e2e_epochs.test.ts index c64ff2d6eda..9f71bfdac2b 100644 --- a/yarn-project/end-to-end/src/e2e_epochs.test.ts +++ b/yarn-project/end-to-end/src/e2e_epochs.test.ts @@ -24,9 +24,9 @@ describe('e2e_epochs', () => { let l1BlockNumber: number; let handle: NodeJS.Timeout; - const EPOCH_DURATION = 4; - const L1_BLOCK_TIME = 5; - const L2_SLOT_DURATION_IN_L1_BLOCKS = 2; + const EPOCH_DURATION_IN_L2_SLOTS = 4; + const L2_SLOT_DURATION_IN_L1_SLOTS = 2; + const L1_BLOCK_TIME_IN_S = 8; beforeAll(async () => { // Set up system without any account nor protocol contracts @@ -35,13 +35,16 @@ describe('e2e_epochs', () => { assumeProvenThrough: undefined, skipProtocolContracts: true, salt: 1, - aztecEpochDuration: EPOCH_DURATION, - aztecSlotDuration: L1_BLOCK_TIME * L2_SLOT_DURATION_IN_L1_BLOCKS, - ethereumSlotDuration: L1_BLOCK_TIME, - aztecEpochProofClaimWindowInL2Slots: EPOCH_DURATION / 2, + aztecEpochDuration: EPOCH_DURATION_IN_L2_SLOTS, + aztecSlotDuration: L1_BLOCK_TIME_IN_S * L2_SLOT_DURATION_IN_L1_SLOTS, + ethereumSlotDuration: L1_BLOCK_TIME_IN_S, + aztecEpochProofClaimWindowInL2Slots: EPOCH_DURATION_IN_L2_SLOTS / 2, minTxsPerBlock: 0, realProofs: false, startProverNode: true, + // This must be enough so that the tx from the prover is delayed properly, + // but not so much to hang the sequencer and timeout the teardown + txPropagationMaxQueryAttempts: 12, }); logger = context.logger; @@ -87,8 +90,8 @@ describe('e2e_epochs', () => { // Constants used for time calculation constants = { - epochDuration: EPOCH_DURATION, - slotDuration: L1_BLOCK_TIME * L2_SLOT_DURATION_IN_L1_BLOCKS, + epochDuration: EPOCH_DURATION_IN_L2_SLOTS, + slotDuration: L1_BLOCK_TIME_IN_S * L2_SLOT_DURATION_IN_L1_SLOTS, l1GenesisBlock: await rollup.getL1StartBlock(), l1GenesisTime: await rollup.getL1GenesisTime(), }; @@ -105,7 +108,7 @@ describe('e2e_epochs', () => { const waitUntilEpochStarts = async (epoch: number) => { const [start] = getTimestampRangeForEpoch(BigInt(epoch), constants); logger.info(`Waiting until L1 timestamp ${start} is reached as the start of epoch ${epoch}`); - await waitUntilL1Timestamp(l1Client, start - BigInt(L1_BLOCK_TIME)); + await waitUntilL1Timestamp(l1Client, start - BigInt(L1_BLOCK_TIME_IN_S)); return start; }; @@ -124,12 +127,14 @@ describe('e2e_epochs', () => { proverDelayer.pauseNextTxUntilTimestamp(epoch2Start); logger.info(`Delayed prover tx until epoch 2 starts at ${epoch2Start}`); - // Wait until the last block of epoch 1 is published and then hold off the sequencer - await waitUntilL2BlockNumber(blockNumberAtEndOfEpoch0 + EPOCH_DURATION); - sequencerDelayer.pauseNextTxUntilTimestamp(epoch2Start + BigInt(L1_BLOCK_TIME)); + // Wait until the last block of epoch 1 is published and then hold off the sequencer. + // Note that the tx below will block the sequencer until it times out + // the txPropagationMaxQueryAttempts until #10824 is fixed. + await waitUntilL2BlockNumber(blockNumberAtEndOfEpoch0 + EPOCH_DURATION_IN_L2_SLOTS); + sequencerDelayer.pauseNextTxUntilTimestamp(epoch2Start + BigInt(L1_BLOCK_TIME_IN_S)); // Next sequencer to publish a block should trigger a rollback to block 1 - await waitUntilL1Timestamp(l1Client, epoch2Start + BigInt(L1_BLOCK_TIME)); + await waitUntilL1Timestamp(l1Client, epoch2Start + BigInt(L1_BLOCK_TIME_IN_S)); expect(await rollup.getBlockNumber()).toEqual(1n); expect(await rollup.getSlotNumber()).toEqual(8n); @@ -142,5 +147,6 @@ describe('e2e_epochs', () => { const lastL2BlockTxReceipt = await l1Client.getTransactionReceipt({ hash: lastL2BlockTxHash! }); expect(lastL2BlockTxReceipt.status).toEqual('success'); expect(lastL2BlockTxReceipt.blockNumber).toBeGreaterThan(lastProverTxReceipt!.blockNumber); + logger.info(`Test succeeded`); }); }); diff --git a/yarn-project/ethereum/src/l1_tx_utils.ts b/yarn-project/ethereum/src/l1_tx_utils.ts index b7eb9493a31..607f06b9567 100644 --- a/yarn-project/ethereum/src/l1_tx_utils.ts +++ b/yarn-project/ethereum/src/l1_tx_utils.ts @@ -1,3 +1,4 @@ +import { times } from '@aztec/foundation/collection'; import { type ConfigMappingsType, bigintConfigHelper, @@ -71,6 +72,11 @@ export interface L1TxUtilsConfig { * How long to wait for a tx to be mined before giving up */ txTimeoutMs?: number; + /** + * How many attempts will be done to get a tx after it was sent? + * First attempt is done at 1s, second at 2s, third at 3s, etc. + */ + txPropagationMaxQueryAttempts?: number; } export const l1TxUtilsConfigMappings: ConfigMappingsType = { @@ -119,6 +125,11 @@ export const l1TxUtilsConfigMappings: ConfigMappingsType = { env: 'L1_TX_MONITOR_TX_TIMEOUT_MS', ...numberConfigHelper(300_000), // 5 mins }, + txPropagationMaxQueryAttempts: { + description: 'How many attempts will be done to get a tx after it was sent', + env: 'L1_TX_PROPAGATION_MAX_QUERY_ATTEMPTS', + ...numberConfigHelper(3), + }, }; export const defaultL1TxUtilsConfig = getDefaultConfig(l1TxUtilsConfigMappings); @@ -213,12 +224,14 @@ export class L1TxUtils { const gasConfig = { ...this.config, ..._gasConfig }; const account = this.walletClient.account; const blobInputs = _blobInputs || {}; + const makeGetTransactionBackoff = () => + makeBackoff(times(gasConfig.txPropagationMaxQueryAttempts ?? 3, i => i + 1)); // Retry a few times, in case the tx is not yet propagated. const tx = await retry( () => this.publicClient.getTransaction({ hash: initialTxHash }), `Getting L1 transaction ${initialTxHash}`, - makeBackoff([1, 2, 3]), + makeGetTransactionBackoff(), this.logger, true, ); @@ -261,7 +274,7 @@ export class L1TxUtils { const tx = await retry( () => this.publicClient.getTransaction({ hash: currentTxHash }), `Getting L1 transaction ${currentTxHash}`, - makeBackoff([1, 2, 3]), + makeGetTransactionBackoff(), this.logger, true, ); diff --git a/yarn-project/ethereum/src/test/tx_delayer.ts b/yarn-project/ethereum/src/test/tx_delayer.ts index f96523dc797..afb117f4ea2 100644 --- a/yarn-project/ethereum/src/test/tx_delayer.ts +++ b/yarn-project/ethereum/src/test/tx_delayer.ts @@ -1,3 +1,4 @@ +import { omit } from '@aztec/foundation/collection'; import { type Logger, createLogger } from '@aztec/foundation/log'; import { retryUntil } from '@aztec/foundation/retry'; @@ -8,6 +9,7 @@ import { type PublicClient, type WalletClient, keccak256, + parseTransaction, publicActions, walletActions, } from 'viem'; @@ -89,6 +91,7 @@ class DelayerImpl implements Delayer { /** * Returns a new client (without modifying the one passed in) with an injected tx delayer. * The delayer can be used to hold off the next tx to be sent until a given block number. + * TODO(#10824): This doesn't play along well with blob txs for some reason. */ export function withDelayer( client: T, @@ -116,16 +119,25 @@ export function withDelayer( // Compute the tx hash manually so we emulate sendRawTransaction response const { serializedTransaction } = args[0]; const txHash = keccak256(serializedTransaction); - logger.info(`Delaying tx ${txHash} until ${inspect(waitUntil)}`); + logger.info(`Delaying tx ${txHash} until ${inspect(waitUntil)}`, { + argsLen: args.length, + ...omit(parseTransaction(serializedTransaction), 'data', 'sidecars'), + }); // Do not await here so we can return the tx hash immediately as if it had been sent on the spot. // Instead, delay it so it lands on the desired block number or timestamp, assuming anvil will // mine it immediately. void wait .then(async () => { - const txHash = await client.sendRawTransaction(...args); - logger.info(`Sent previously delayed tx ${txHash} to land on ${inspect(waitUntil)}`); - delayer.txs.push(txHash); + const clientTxHash = await client.sendRawTransaction(...args); + if (clientTxHash !== txHash) { + logger.error(`Tx hash returned by the client does not match computed one`, { + clientTxHash, + computedTxHash: txHash, + }); + } + logger.info(`Sent previously delayed tx ${clientTxHash} to land on ${inspect(waitUntil)}`); + delayer.txs.push(clientTxHash); }) .catch(err => logger.error(`Error sending tx after delay`, err)); diff --git a/yarn-project/foundation/src/config/env_var.ts b/yarn-project/foundation/src/config/env_var.ts index ad999367e4f..76c58270b1f 100644 --- a/yarn-project/foundation/src/config/env_var.ts +++ b/yarn-project/foundation/src/config/env_var.ts @@ -183,6 +183,7 @@ export type EnvVar = | 'L1_TX_MONITOR_CHECK_INTERVAL_MS' | 'L1_TX_MONITOR_STALL_TIME_MS' | 'L1_TX_MONITOR_TX_TIMEOUT_MS' + | 'L1_TX_PROPAGATION_MAX_QUERY_ATTEMPTS' | 'FAUCET_MNEMONIC_ACCOUNT_INDEX' | 'FAUCET_ETH_AMOUNT' | 'FAUCET_INTERVAL_MS'