Merge pull request #6138 from roberto-bayardo/proposer-failure-debug

prevent op-proposer Send tx failure errors & clean up op-proposer logging

op-challenger/fault/responder_test.go

@@ -40,6 +40,10 @@ func (m *mockTxManager) Send(ctx context.Context, candidate txmgr.TxCandidate) (
 	), nil
 }
 
+func (m *mockTxManager) BlockNumber(ctx context.Context) (uint64, error) {
+	panic("not implemented")
+}
+
 func (m *mockTxManager) From() common.Address {
 	return m.from
 }

op-e2e/actions/l2_proposer.go

@@ -44,6 +44,9 @@ type fakeTxMgr struct {
 func (f fakeTxMgr) From() common.Address {
 	return f.from
 }
+func (f fakeTxMgr) BlockNumber(_ context.Context) (uint64, error) {
+	panic("unimplemented")
+}
 func (f fakeTxMgr) Send(_ context.Context, _ txmgr.TxCandidate) (*types.Receipt, error) {
 	panic("unimplemented")
 }

op-proposer/proposer/l2_output_submitter.go

@@ -259,6 +259,7 @@ func (l *L2OutputSubmitter) FetchNextOutputInfo(ctx context.Context) (*eth.Outpu
 		l.log.Error("proposer unable to get sync status", "err", err)
 		return nil, false, err
 	}
+
 	// Use either the finalized or safe head depending on the config. Finalized head is default & safer.
 	var currentBlockNumber *big.Int
 	if l.allowNonFinalized {
@@ -268,14 +269,14 @@ func (l *L2OutputSubmitter) FetchNextOutputInfo(ctx context.Context) (*eth.Outpu
 	}
 	// Ensure that we do not submit a block in the future
 	if currentBlockNumber.Cmp(nextCheckpointBlock) < 0 {
-		l.log.Info("proposer submission interval has not elapsed", "currentBlockNumber", currentBlockNumber, "nextBlockNumber", nextCheckpointBlock)
+		l.log.Debug("proposer submission interval has not elapsed", "currentBlockNumber", currentBlockNumber, "nextBlockNumber", nextCheckpointBlock)
 		return nil, false, nil
 	}
 
-	return l.fetchOuput(ctx, nextCheckpointBlock)
+	return l.fetchOutput(ctx, nextCheckpointBlock)
 }
 
-func (l *L2OutputSubmitter) fetchOuput(ctx context.Context, block *big.Int) (*eth.OutputResponse, bool, error) {
+func (l *L2OutputSubmitter) fetchOutput(ctx context.Context, block *big.Int) (*eth.OutputResponse, bool, error) {
 	ctx, cancel := context.WithTimeout(ctx, l.networkTimeout)
 	defer cancel()
 	output, err := l.rollupClient.OutputAtBlock(ctx, block.Uint64())
@@ -319,8 +320,41 @@ func proposeL2OutputTxData(abi *abi.ABI, output *eth.OutputResponse) ([]byte, er
 		new(big.Int).SetUint64(output.Status.CurrentL1.Number))
 }
 
+// We wait until l1head advances beyond blocknum. This is used to make sure proposal tx won't
+// immediately fail when checking the l1 blockhash. Note that EstimateGas uses "latest" state to
+// execute the transaction by default, meaning inside the call, the head block is considered
+// "pending" instead of committed. In the case l1blocknum == l1head then, blockhash(l1blocknum)
+// will produce a value of 0 within EstimateGas, and the call will fail when the contract checks
+// that l1blockhash matches blockhash(l1blocknum).
+func (l *L2OutputSubmitter) waitForL1Head(ctx context.Context, blockNum uint64) error {
+	ticker := time.NewTicker(l.pollInterval)
+	defer ticker.Stop()
+	l1head, err := l.txMgr.BlockNumber(ctx)
+	if err != nil {
+		return err
+	}
+	for l1head <= blockNum {
+		l.log.Debug("waiting for l1 head > l1blocknum1+1", "l1head", l1head, "l1blocknum", blockNum)
+		select {
+		case <-ticker.C:
+			l1head, err = l.txMgr.BlockNumber(ctx)
+			if err != nil {
+				return err
+			}
+			break
+		case <-l.done:
+			return fmt.Errorf("L2OutputSubmitter is done()")
+		}
+	}
+	return nil
+}
+
 // sendTransaction creates & sends transactions through the underlying transaction manager.
 func (l *L2OutputSubmitter) sendTransaction(ctx context.Context, output *eth.OutputResponse) error {
+	err := l.waitForL1Head(ctx, output.Status.HeadL1.Number+1)
+	if err != nil {
+		return err
+	}
 	data, err := l.ProposeL2OutputTxData(output)
 	if err != nil {
 		return err
@@ -336,7 +370,10 @@ func (l *L2OutputSubmitter) sendTransaction(ctx context.Context, output *eth.Out
 	if receipt.Status == types.ReceiptStatusFailed {
 		l.log.Error("proposer tx successfully published but reverted", "tx_hash", receipt.TxHash)
 	} else {
-		l.log.Info("proposer tx successfully published", "tx_hash", receipt.TxHash)
+		l.log.Info("proposer tx successfully published",
+			"tx_hash", receipt.TxHash,
+			"l1blocknum", output.Status.CurrentL1.Number,
+			"l1blockhash", output.Status.CurrentL1.Hash)
 	}
 	return nil
 }
@@ -359,10 +396,13 @@ func (l *L2OutputSubmitter) loop() {
 			if !shouldPropose {
 				break
 			}
-
 			cCtx, cancel := context.WithTimeout(ctx, 10*time.Minute)
 			if err := l.sendTransaction(cCtx, output); err != nil {
-				l.log.Error("Failed to send proposal transaction", "err", err)
+				l.log.Error("Failed to send proposal transaction",
+					"err", err,
+					"l1blocknum", output.Status.CurrentL1.Number,
+					"l1blockhash", output.Status.CurrentL1.Hash,
+					"l1head", output.Status.HeadL1.Number)
 				cancel()
 				break
 			}

op-service/txmgr/mocks/TxManager.go

@@ -19,6 +19,30 @@ type TxManager struct {
 	mock.Mock
 }
 
+// BlockNumber provides a mock function with given fields: ctx
+func (_m *TxManager) BlockNumber(ctx context.Context) (uint64, error) {
+	ret := _m.Called(ctx)
+
+	var r0 uint64
+	var r1 error
+	if rf, ok := ret.Get(0).(func(context.Context) (uint64, error)); ok {
+		return rf(ctx)
+	}
+	if rf, ok := ret.Get(0).(func(context.Context) uint64); ok {
+		r0 = rf(ctx)
+	} else {
+		r0 = ret.Get(0).(uint64)
+	}
+
+	if rf, ok := ret.Get(1).(func(context.Context) error); ok {
+		r1 = rf(ctx)
+	} else {
+		r1 = ret.Error(1)
+	}
+
+	return r0, r1
+}
+
 // From provides a mock function with given fields:
 func (_m *TxManager) From() common.Address {
 	ret := _m.Called()

op-service/txmgr/txmgr.go

@@ -48,6 +48,9 @@ type TxManager interface {
 	// From returns the sending address associated with the instance of the transaction manager.
 	// It is static for a single instance of a TxManager.
 	From() common.Address
+
+	// BlockNumber returns the most recent block number from the underlying network.
+	BlockNumber(ctx context.Context) (uint64, error)
 }
 
 // ETHBackend is the set of methods that the transaction manager uses to resubmit gas & determine
@@ -116,6 +119,10 @@ func (m *SimpleTxManager) From() common.Address {
 	return m.cfg.From
 }
 
+func (m *SimpleTxManager) BlockNumber(ctx context.Context) (uint64, error) {
+	return m.backend.BlockNumber(ctx)
+}
+
 // TxCandidate is a transaction candidate that can be submitted to ask the
 // [TxManager] to construct a transaction with gas price bounds.
 type TxCandidate struct {
@@ -353,7 +360,8 @@ func (m *SimpleTxManager) publishAndWaitForTx(ctx context.Context, tx *types.Tra
 	// Poll for the transaction to be ready & then send the result to receiptChan
 	receipt, err := m.waitMined(ctx, tx, sendState)
 	if err != nil {
-		log.Warn("Transaction receipt not found", "err", err)
+		// this will happen if the tx was successfully replaced by a tx with bumped fees
+		log.Info("Transaction receipt not found", "err", err)
 		return
 	}
 	select {
@@ -475,6 +483,10 @@ func (m *SimpleTxManager) increaseGasPrice(ctx context.Context, tx *types.Transa
 		Data:      rawTx.Data,
 	})
 	if err != nil {
+		// If this is a transaction resubmission, we sometimes see this outcome because the
+		// original tx can get included in a block just before the above call. In this case the
+		// error is due to the tx reverting with message "block number must be equal to next
+		// expected block number"
 		m.l.Warn("failed to re-estimate gas", "err", err, "gaslimit", tx.Gas())
 		return nil, err
 	}