op-supervisor: resetTracker fixes (#16028)

* op-supervisor: resetTracker draft changes

Co-authored-by: Sebastian Stammler <[email protected]>

* op-supervisor: syncnode reset tracker fixes

* op-acceptance-tests: unlock sequencing window expiry test

* op-supervisor,op-node,tests: fix sequencing window expiry test

* op-supervisor,tests: fix review / ci

---------

Co-authored-by: Sebastian Stammler <[email protected]>

Author: protolambda

op-acceptance-tests/tests/interop/seqwindow/expiry_test.go

@@ -1,6 +1,7 @@
 package seqwindow
 
 import (
+	"strings"
 	"testing"
 	"time"
 
@@ -9,14 +10,14 @@ import (
 	"github.com/ethereum-optimism/optimism/op-devstack/devtest"
 	"github.com/ethereum-optimism/optimism/op-devstack/presets"
 	"github.com/ethereum-optimism/optimism/op-service/eth"
+	"github.com/ethereum-optimism/optimism/op-service/retry"
 )
 
 // TestSequencingWindowExpiry tests that the sequencing window may expire,
 // the chain reorgs because of it, and that the chain then recovers.
+// This test can take 3 minutes to run.
 func TestSequencingWindowExpiry(gt *testing.T) {
 	t := devtest.SerialT(gt)
-	// TODO(#15769): fix sequencing-window expiry interop functionality
-	t.Skip("Interop sequencing-window expiry interaction is known to not fully work yet.")
 
 	sys := presets.NewSimpleInterop(t)
 	require := t.Require()
@@ -39,7 +40,14 @@ func TestSequencingWindowExpiry(gt *testing.T) {
 	t.Logger().Info("Tx 1 is safe now")
 
 	// Stop the batcher of chain A, so the L2 unsafe blocks will not get submitted.
-	require.NoError(sys.L2BatcherA.ActivityAPI().StopBatcher(t.Ctx()))
+	// This may take a while, since the batcher is still actively submitting new data.
+	require.NoError(retry.Do0(t.Ctx(), 10, retry.Exponential(), func() error {
+		err := sys.L2BatcherA.ActivityAPI().StopBatcher(t.Ctx())
+		if err != nil && strings.Contains(err.Error(), "batcher is not running") {
+			return nil
+		}
+		return err
+	}))
 	stoppedAt := sys.L1Network.WaitForBlock() // wait for new block, in case there is any batch left
 	// Make sure the supervisor has synced enough of the L1, for the local-safe query to work.
 	sys.Supervisor.AwaitMinL1(stoppedAt.Number)
@@ -75,13 +83,34 @@ func TestSequencingWindowExpiry(gt *testing.T) {
 		"tx", receipt2.TxHash, "l2Block", old)
 	// The logs will show a "Chain reorg detected" from op-geth.
 
+	// Once this happens we don't want to continue to try and include the tx in a block again,
+	// since that will then be reorged out again.
+	// We need to enter recovery-mode to not continue to build an incompatible chain that will not get submitted.
+	// It may reorg once more, but then stays compatible.
+	// For a while we'll have to build blocks that are not going to be reorged out due to subtle L1 origin divergence.
+	t.Logger().Info("Turning on recovery-mode")
+	t.Require().NoError(sys.L2CLA.Escape().RollupAPI().SetRecoverMode(t.Ctx(), true))
+
 	t.Logger().Info("Waiting for sequencing window expiry induced reorg now")
 	// Monitor that the old unsafe chain is reorged out as expected
 	require.Eventually(func() bool {
 		latest := sys.L2ELA.BlockRefByNumber(old.Number)
 		return latest.Hash != old.Hash
 	}, windowDuration+time.Second*20, time.Second, "expecting old block to be reorged out")
 
+	// Wait for the tx to no longer be included.
+	// The tx-indexer may still return the old block or be stale.
+	// So instead, lookup the tx nonce
+	require.Eventually(func() bool {
+		latestNonce, err := sys.L2ELA.Escape().EthClient().NonceAt(t.Ctx(), alice.Address(), nil)
+		if err != nil {
+			t.Logger().Error("Failed to look up pending nonce")
+			return false
+		}
+		t.Logger().Info("Checking tx 2 nonce", "latest", latestNonce, "tx2", tx2.Nonce.Value())
+		return latestNonce <= tx2.Nonce.Value()
+	}, windowDuration+time.Second*20, time.Second, "tx should be reorged out and not come back")
+
 	t.Logger().Info("Waiting for supervisor to surpass pre-reorg chain now")
 	// Monitor that the supervisor can continue to sync.
 	// A lot more blocks will expire first; the local-safe chain will be entirely force-derived blocks.
@@ -102,6 +131,39 @@ func TestSequencingWindowExpiry(gt *testing.T) {
 	other := sys.L2ELA.BlockRefByNumber(safe.Derived.Number)
 	require.Equal(safe.Derived.Hash, other.Hash, "supervisor must match chain with EL")
 
+	t.Logger().Info("Re-enabling batch-submitter")
 	// re-enable the batcher now that we are done with the test.
 	t.Require().NoError(sys.L2BatcherA.ActivityAPI().StartBatcher(t.Ctx()))
+	// TODO(#16036): batcher submits future span batch, misses a L2 block.
+	// For now it uses singular batches to work-around.
+
+	// Build the missing blocks, catch up on local-safe chain
+	t.Require().Eventually(func() bool {
+		status := sys.L2CLA.SyncStatus()
+		return status.LocalSafeL2.Number+10 > status.UnsafeL2.Number
+	}, windowDuration, time.Second*2, "wait for local-safe to recover near unsafe head")
+
+	// Once we have enough margin to not get reorged again before the batch-submitter acts,
+	// exit recovery mode, so we can include txs again.
+	t.Logger().Info("Exiting recovery mode")
+	t.Require().NoError(sys.L2CLA.Escape().RollupAPI().SetRecoverMode(t.Ctx(), false))
+
+	// Now confirm a tx, chain should be healthy again.
+	tx3 := alice.Transfer(common.HexToAddress("0x7777"), eth.GWei(100))
+	receipt3, err := tx3.Included.Eval(t.Ctx())
+	require.NoError(err)
+	t.Logger().Info("Confirmed tx 3", "tx", receipt3.TxHash, "block", receipt3.BlockHash)
+
+	// Wait for the first tx to become cross-safe.
+	// We are not interested in the sequencing window to expire and revert all the way back to 0.
+	require.Eventually(func() bool {
+		status := sys.L2CLA.SyncStatus()
+		t.Logger().Info("Awaiting tx safety",
+			"local-unsafe", status.UnsafeL2, "local-safe", status.LocalSafeL2)
+		return status.SafeL2.Number > receipt3.BlockNumber.Uint64()
+	}, time.Second*60, time.Second, "wait for tx 3 to be safe")
+	t.Logger().Info("Tx 3 is safe now")
+	// Sanity check the block the tx was included is really still canonical
+	got := sys.L2ELA.BlockRefByNumber(receipt3.BlockNumber.Uint64())
+	t.Require().Equal(receipt3.BlockHash, got.Hash, "tx 3 was included in canonical block")
 }

op-acceptance-tests/tests/interop/seqwindow/init_test.go

@@ -3,13 +3,24 @@ package seqwindow
 import (
 	"testing"
 
+	bss "github.com/ethereum-optimism/optimism/op-batcher/batcher"
 	"github.com/ethereum-optimism/optimism/op-devstack/presets"
+	"github.com/ethereum-optimism/optimism/op-devstack/stack"
+	"github.com/ethereum-optimism/optimism/op-devstack/sysgo"
+	"github.com/ethereum-optimism/optimism/op-node/rollup/derive"
 )
 
 func TestMain(m *testing.M) {
 	presets.DoMain(m,
 		presets.WithSimpleInterop(),
 		// Short enough that we can run the test,
 		// long enough that the batcher can still submit something before we make things expire.
-		presets.WithSequencingWindow(10, 30))
+		presets.WithSequencingWindow(10, 30),
+		stack.MakeCommon(sysgo.WithBatcherOption(func(id stack.L2BatcherID, cfg *bss.CLIConfig) {
+			// Span-batches during recovery don't appear to align well with the starting-point.
+			// It can be off by ~6 L2 blocks, possibly due to off-by-one
+			// in L1 block sync considerations in batcher stop or start.
+			// So we end up having to encode block by block, so the full batch data does not get dropped.
+			cfg.BatchType = derive.SingularBatchType
+		})))
 }

op-devstack/sysgo/l2_batcher.go

@@ -44,6 +44,14 @@ func (b *L2Batcher) hydrate(system stack.ExtensibleSystem) {
 	l2Net.(stack.ExtensibleL2Network).AddL2Batcher(bFrontend)
 }
 
+type BatcherOption func(id stack.L2BatcherID, cfg *bss.CLIConfig)
+
+func WithBatcherOption(opt BatcherOption) stack.Option[*Orchestrator] {
+	return stack.Deploy[*Orchestrator](func(orch *Orchestrator) {
+		orch.batcherOptions = append(orch.batcherOptions, opt)
+	})
+}
+
 func WithBatcher(batcherID stack.L2BatcherID, l1ELID stack.L1ELNodeID, l2CLID stack.L2CLNodeID, l2ELID stack.L2ELNodeID) stack.Option[*Orchestrator] {
 	return stack.AfterDeploy(func(orch *Orchestrator) {
 		require := orch.P().Require()
@@ -94,12 +102,16 @@ func WithBatcher(batcherID stack.L2BatcherID, l1ELID stack.L1ELNodeID, l2CLID st
 			Stopped:               false,
 			BatchType:             derive.SpanBatchType,
 			MaxBlocksPerSpanBatch: 10,
+			PreferLocalSafeL2:     l2CL.cfg.Rollup.InteropTime != nil,
 			DataAvailabilityType:  batcherFlags.CalldataType,
 			CompressionAlgo:       derive.Brotli,
 			RPC: oprpc.CLIConfig{
 				EnableAdmin: true,
 			},
 		}
+		for _, opt := range orch.batcherOptions {
+			opt(batcherID, batcherCLIConfig)
+		}
 
 		batcher, err := bss.BatcherServiceFromCLIConfig(
 			orch.P().Ctx(), "0.0.1", batcherCLIConfig,

op-devstack/sysgo/orchestrator.go

@@ -26,6 +26,9 @@ type Orchestrator struct {
 	// nil if no time travel is supported
 	timeTravelClock *clock.AdvancingClock
 
+	// options
+	batcherOptions []BatcherOption
+
 	superchains locks.RWMap[stack.SuperchainID, *Superchain]
 	clusters    locks.RWMap[stack.ClusterID, *Cluster]
 	l1Nets      locks.RWMap[eth.ChainID, *L1Network]

op-node/rollup/derive/base_batch_stage.go

@@ -188,7 +188,7 @@ func (bs *baseBatchStage) deriveNextEmptyBatch(ctx context.Context, outOfData bo
 	// to preserve that L2 time >= L1 time. If this is the first block of the epoch, always generate a
 	// batch to ensure that we at least have one batch per epoch.
 	if nextTimestamp < nextEpoch.Time || firstOfEpoch {
-		bs.log.Info("Generating next batch", "epoch", epoch, "timestamp", nextTimestamp)
+		bs.log.Info("Generating next batch", "epoch", epoch, "timestamp", nextTimestamp, "parent", parent)
 		return &SingularBatch{
 			ParentHash:   parent.Hash,
 			EpochNum:     rollup.Epoch(epoch.Number),

op-service/apis/eth.go

@@ -109,6 +109,9 @@ type TransactionSender interface {
 type EthNonce interface {
 	// PendingNonceAt returns the account nonce of the given account in the pending state.
 	PendingNonceAt(ctx context.Context, account common.Address) (uint64, error)
+	// NonceAt returns the account nonce of the given account in the state at the given block number.
+	// A nil block number may be used to get the latest state.
+	NonceAt(ctx context.Context, account common.Address, blockNumber *big.Int) (uint64, error)
 }
 
 type EthBalance interface {

op-service/sources/eth_client.go

@@ -548,6 +548,14 @@ func (s *EthClient) PendingNonceAt(ctx context.Context, account common.Address)
 	return uint64(result), err
 }
 
+// NonceAt returns the account nonce of the given account in the state at the given block number.
+// A nil block number may be used to get the latest state.
+func (s *EthClient) NonceAt(ctx context.Context, account common.Address, blockNumber *big.Int) (uint64, error) {
+	var result hexutil.Uint64
+	err := s.client.CallContext(ctx, &result, "eth_getTransactionCount", account, toBlockNumArg(blockNumber))
+	return uint64(result), err
+}
+
 func toBlockNumArg(number *big.Int) string {
 	if number == nil {
 		return "latest"

op-supervisor/supervisor/backend/rewinder/rewinder.go

@@ -135,6 +135,7 @@ func (r *Rewinder) handleLocalDerivedEvent(ev superevents.LocalSafeUpdateEvent)
 		break
 	}
 
+	r.log.Warn("Rewinding logs DB", "chain", ev.ChainID, "target", target)
 	// Try to rewind and stop if it succeeds
 	err = r.db.RewindLogs(ev.ChainID, target)
 	if err != nil {

op-supervisor/supervisor/backend/syncnode/node.go

@@ -449,63 +449,30 @@ func (m *ManagedNode) Close() error {
 func (m *ManagedNode) resetIfInconsistent() {
 	ctx, cancel := context.WithTimeout(m.ctx, internalTimeout)
 	defer cancel()
-
-	// Handle the given seen block from the node if it is an inconsistency.
-	handle := func(name string, seenFromNode eth.BlockID) (inconsistent bool) {
-		if seenFromNode == (eth.BlockID{}) {
-			return false // if we haven't seen anything, then don't reset to it
-		}
-		// We know the last block from the op-node.
-		// Ae may have references that:
-		//   - local-unsafe matches, and local-safe matches -> no inconsistency caused by latest signaled local-unsafe!
-		//   - local-unsafe matches, but local-safe differs -> e.g. if local-safe is behind and does not know about this block
-		//   - local-unsafe differs, but local-safe matches  -> we should stick to the local-safe chain, not rewind further, but may need to rewind some
-		//   - local-unsafe differs, and local-safe differs -> we should use the local-safe chain as truth
-		//
-		// And never should we reset if the node is just ahead of us; resetIfAhead handles that.
-
-		m.log.Debug("Checking last seen block from node for consistency", "safety", name, "block", seenFromNode)
-		localUnsafeMatchErr := m.backend.IsLocalUnsafe(ctx, m.chainID, seenFromNode)
-		if errors.Is(localUnsafeMatchErr, types.ErrFuture) {
-			localUnsafeMatchErr = nil // do not count it when the node is ahead of us
-		}
-		if localUnsafeMatchErr != nil {
-			m.log.Warn("Last seen block from node is inconsistent with supervisor local-unsafe blocks",
-				"safety", name, "err", localUnsafeMatchErr)
-		}
-		localSafeMatchErr := m.backend.IsLocalSafe(ctx, m.chainID, seenFromNode)
-		if errors.Is(localSafeMatchErr, types.ErrFuture) {
-			localSafeMatchErr = nil // do not count it when the node is ahead of us
-		}
-		if localSafeMatchErr != nil {
-			m.log.Warn("Last seen block from node is inconsistent with supervisor local-safe blocks",
-				"safety", name, "err", localSafeMatchErr)
-		}
-		if localUnsafeMatchErr != nil || localSafeMatchErr != nil {
-			// If either mismatches, we want to reset back no further than latest local-safe
-			localSafe, err := m.backend.LocalSafe(ctx, m.chainID)
-			if err != nil {
-				m.log.Debug("Cannot determine how to handle inconsistency, no local-safe data available",
-					"localUnsafeMatchErr", localUnsafeMatchErr,
-					"localSafeMatchErr", localSafeMatchErr, "err", err)
-				return false
-			}
-			if m.lastNodeLocalUnsafe.Number > localSafe.Derived.Number {
-				m.resetTracker.beginBisectionReset(m.lastNodeLocalUnsafe)
-			} else {
-				m.resetTracker.beginBisectionReset(localSafe.Derived)
-			}
-			return true
-		}
-		return false
+	seenFromNode := m.lastNodeLocalSafe
+	name := "local-safe"
+	if seenFromNode == (eth.BlockID{}) {
+		return // if we haven't seen anything, then don't reset to it
 	}
-	if handle("local-unsafe", m.lastNodeLocalUnsafe) {
+	m.log.Debug("Checking last seen block from node for consistency", "safety", name, "block", seenFromNode)
+	localSafeMatchErr := m.backend.IsLocalSafe(ctx, m.chainID, seenFromNode)
+	if localSafeMatchErr == nil {
 		return
 	}
-	if handle("local-safe", m.lastNodeLocalSafe) {
+	if errors.Is(localSafeMatchErr, types.ErrFuture) {
+		m.log.Debug("node is ahead of op-supervisor local-safe data")
+		return // resetIfAhead will handle this
+	}
+	m.log.Warn("Last seen block from node is inconsistent with supervisor local-safe blocks",
+		"safety", name, "err", localSafeMatchErr)
+	// If there is a mismatch, we want to reset back no further than latest local-safe
+	localSafe, err := m.backend.LocalSafe(ctx, m.chainID)
+	if err != nil {
+		m.log.Debug("Cannot determine how to handle inconsistency, no local-safe data available",
+			"localSafeMatchErr", localSafeMatchErr, "err", err)
 		return
 	}
-	m.log.Debug("no inconsistency found")
+	m.resetTracker.beginBisectionReset(localSafe.Derived)
 }
 
 // resetIfAhead checks if the node is ahead of the local-safe db

op-supervisor/supervisor/backend/syncnode/node_test.go

@@ -139,7 +139,7 @@ func TestPrepareReset(t *testing.T) {
 		pivot = i
 		node.resetTracker.bisectToTarget()
 		require.Equal(t, i, unsafe.Number)
-		require.Equal(t, uint64(0), safe.Number)
+		require.Equal(t, i, safe.Number)
 		require.Equal(t, uint64(0), finalized.Number)
 	}