Merge branch 'develop' into felipe/track-nonce-locally

op-challenger/game/fault/agent.go

@@ -7,6 +7,7 @@ import (
 
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/solver"
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/types"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum/go-ethereum/log"
 )
 
@@ -24,6 +25,7 @@ type ClaimLoader interface {
 }
 
 type Agent struct {
+	metrics                 metrics.Metricer
 	solver                  *solver.Solver
 	loader                  ClaimLoader
 	responder               Responder
@@ -33,8 +35,9 @@ type Agent struct {
 	log                     log.Logger
 }
 
-func NewAgent(loader ClaimLoader, maxDepth int, trace types.TraceProvider, responder Responder, updater types.OracleUpdater, agreeWithProposedOutput bool, log log.Logger) *Agent {
+func NewAgent(m metrics.Metricer, loader ClaimLoader, maxDepth int, trace types.TraceProvider, responder Responder, updater types.OracleUpdater, agreeWithProposedOutput bool, log log.Logger) *Agent {
 	return &Agent{
+		metrics:                 m,
 		solver:                  solver.NewSolver(maxDepth, trace),
 		loader:                  loader,
 		responder:               responder,
@@ -134,6 +137,7 @@ func (a *Agent) move(ctx context.Context, claim types.Claim, game types.Game) er
 		log.Debug("Skipping duplicate move")
 		return nil
 	}
+	a.metrics.RecordGameMove()
 	log.Info("Performing move")
 	return a.responder.Respond(ctx, move)
 }
@@ -170,6 +174,7 @@ func (a *Agent) step(ctx context.Context, claim types.Claim, game types.Game) er
 
 	a.log.Info("Performing step", "is_attack", step.IsAttack,
 		"depth", step.LeafClaim.Depth(), "index_at_depth", step.LeafClaim.IndexAtDepth(), "value", step.LeafClaim.Value)
+	a.metrics.RecordGameStep()
 	callData := types.StepCallData{
 		ClaimIndex: uint64(step.LeafClaim.ContractIndex),
 		IsAttack:   step.IsAttack,

op-challenger/game/fault/agent_test.go

@@ -5,6 +5,7 @@ import (
 	"testing"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/types"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/stretchr/testify/require"
 
@@ -16,14 +17,14 @@ func TestShouldResolve(t *testing.T) {
 	log := testlog.Logger(t, log.LvlCrit)
 
 	t.Run("AgreeWithProposedOutput", func(t *testing.T) {
-		agent := NewAgent(nil, 0, nil, nil, nil, true, log)
+		agent := NewAgent(metrics.NoopMetrics, nil, 0, nil, nil, nil, true, log)
 		require.False(t, agent.shouldResolve(context.Background(), types.GameStatusDefenderWon))
 		require.True(t, agent.shouldResolve(context.Background(), types.GameStatusChallengerWon))
 		require.False(t, agent.shouldResolve(context.Background(), types.GameStatusInProgress))
 	})
 
 	t.Run("DisagreeWithProposedOutput", func(t *testing.T) {
-		agent := NewAgent(nil, 0, nil, nil, nil, false, log)
+		agent := NewAgent(metrics.NoopMetrics, nil, 0, nil, nil, nil, false, log)
 		require.True(t, agent.shouldResolve(context.Background(), types.GameStatusDefenderWon))
 		require.False(t, agent.shouldResolve(context.Background(), types.GameStatusChallengerWon))
 		require.False(t, agent.shouldResolve(context.Background(), types.GameStatusInProgress))

op-challenger/game/fault/player.go

@@ -11,6 +11,7 @@ import (
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/trace/alphabet"
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/trace/cannon"
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/types"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-service/txmgr"
 	"github.com/ethereum/go-ethereum/accounts/abi/bind"
 	"github.com/ethereum/go-ethereum/common"
@@ -37,6 +38,7 @@ type GamePlayer struct {
 func NewGamePlayer(
 	ctx context.Context,
 	logger log.Logger,
+	m metrics.Metricer,
 	cfg *config.Config,
 	dir string,
 	addr common.Address,
@@ -79,7 +81,7 @@ func NewGamePlayer(
 	var updater types.OracleUpdater
 	switch cfg.TraceType {
 	case config.TraceTypeCannon:
-		cannonProvider, err := cannon.NewTraceProvider(ctx, logger, cfg, client, dir, addr)
+		cannonProvider, err := cannon.NewTraceProvider(ctx, logger, m, cfg, client, dir, addr)
 		if err != nil {
 			return nil, fmt.Errorf("create cannon trace provider: %w", err)
 		}
@@ -105,7 +107,7 @@ func NewGamePlayer(
 	}
 
 	return &GamePlayer{
-		act:                     NewAgent(loader, int(gameDepth), provider, responder, updater, cfg.AgreeWithProposedOutput, logger).Act,
+		act:                     NewAgent(m, loader, int(gameDepth), provider, responder, updater, cfg.AgreeWithProposedOutput, logger).Act,
 		agreeWithProposedOutput: cfg.AgreeWithProposedOutput,
 		loader:                  loader,
 		logger:                  logger,

op-challenger/game/fault/trace/cannon/executor.go

@@ -11,6 +11,7 @@ import (
 	"regexp"
 	"strconv"
 	"strings"
+	"time"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/config"
 	oplog "github.com/ethereum-optimism/optimism/op-service/log"
@@ -30,6 +31,7 @@ type cmdExecutor func(ctx context.Context, l log.Logger, binary string, args ...
 
 type Executor struct {
 	logger           log.Logger
+	metrics          CannonMetricer
 	l1               string
 	l2               string
 	inputs           LocalGameInputs
@@ -45,9 +47,10 @@ type Executor struct {
 	cmdExecutor      cmdExecutor
 }
 
-func NewExecutor(logger log.Logger, cfg *config.Config, inputs LocalGameInputs) *Executor {
+func NewExecutor(logger log.Logger, m CannonMetricer, cfg *config.Config, inputs LocalGameInputs) *Executor {
 	return &Executor{
 		logger:           logger,
+		metrics:          m,
 		l1:               cfg.L1EthRpc,
 		l2:               cfg.CannonL2,
 		inputs:           inputs,
@@ -119,7 +122,13 @@ func (e *Executor) GenerateProof(ctx context.Context, dir string, i uint64) erro
 		return fmt.Errorf("could not create proofs directory %v: %w", proofDir, err)
 	}
 	e.logger.Info("Generating trace", "proof", i, "cmd", e.cannon, "args", strings.Join(args, ", "))
-	return e.cmdExecutor(ctx, e.logger.New("proof", i), e.cannon, args...)
+	execStart := time.Now()
+	err = e.cmdExecutor(ctx, e.logger.New("proof", i), e.cannon, args...)
+	if err != nil {
+		execDuration := time.Since(execStart).Seconds()
+		e.metrics.RecordCannonExecutionTime(execDuration)
+	}
+	return err
 }
 
 func runCmd(ctx context.Context, l log.Logger, binary string, args ...string) error {

op-challenger/game/fault/trace/cannon/executor_test.go

@@ -11,6 +11,7 @@ import (
 	"time"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/config"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-node/testlog"
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/log"
@@ -39,7 +40,7 @@ func TestGenerateProof(t *testing.T) {
 		L2BlockNumber: big.NewInt(3333),
 	}
 	captureExec := func(t *testing.T, cfg config.Config, proofAt uint64) (string, string, map[string]string) {
-		executor := NewExecutor(testlog.Logger(t, log.LvlInfo), &cfg, inputs)
+		executor := NewExecutor(testlog.Logger(t, log.LvlInfo), metrics.NoopMetrics, &cfg, inputs)
 		executor.selectSnapshot = func(logger log.Logger, dir string, absolutePreState string, i uint64) (string, error) {
 			return input, nil
 		}

op-challenger/game/fault/trace/cannon/provider.go

@@ -33,6 +33,10 @@ type proofData struct {
 	OracleOffset uint32        `json:"oracle-offset,omitempty"`
 }
 
+type CannonMetricer interface {
+	RecordCannonExecutionTime(t float64)
+}
+
 type ProofGenerator interface {
 	// GenerateProof executes cannon to generate a proof at the specified trace index in dataDir.
 	GenerateProof(ctx context.Context, dataDir string, proofAt uint64) error
@@ -51,7 +55,7 @@ type CannonTraceProvider struct {
 	lastProof *proofData
 }
 
-func NewTraceProvider(ctx context.Context, logger log.Logger, cfg *config.Config, l1Client bind.ContractCaller, dir string, gameAddr common.Address) (*CannonTraceProvider, error) {
+func NewTraceProvider(ctx context.Context, logger log.Logger, m CannonMetricer, cfg *config.Config, l1Client bind.ContractCaller, dir string, gameAddr common.Address) (*CannonTraceProvider, error) {
 	l2Client, err := ethclient.DialContext(ctx, cfg.CannonL2)
 	if err != nil {
 		return nil, fmt.Errorf("dial l2 client %v: %w", cfg.CannonL2, err)
@@ -65,15 +69,15 @@ func NewTraceProvider(ctx context.Context, logger log.Logger, cfg *config.Config
 	if err != nil {
 		return nil, fmt.Errorf("fetch local game inputs: %w", err)
 	}
-	return NewTraceProviderFromInputs(logger, cfg, localInputs, dir), nil
+	return NewTraceProviderFromInputs(logger, m, cfg, localInputs, dir), nil
 }
 
-func NewTraceProviderFromInputs(logger log.Logger, cfg *config.Config, localInputs LocalGameInputs, dir string) *CannonTraceProvider {
+func NewTraceProviderFromInputs(logger log.Logger, m CannonMetricer, cfg *config.Config, localInputs LocalGameInputs, dir string) *CannonTraceProvider {
 	return &CannonTraceProvider{
 		logger:    logger,
 		dir:       dir,
 		prestate:  cfg.CannonAbsolutePreState,
-		generator: NewExecutor(logger, cfg, localInputs),
+		generator: NewExecutor(logger, m, cfg, localInputs),
 	}
 }
 

op-challenger/game/monitor.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/game/scheduler"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-service/clock"
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/log"
@@ -26,6 +27,7 @@ type gameScheduler interface {
 
 type gameMonitor struct {
 	logger           log.Logger
+	metrics          metrics.Metricer
 	clock            clock.Clock
 	source           gameSource
 	scheduler        gameScheduler
@@ -36,6 +38,7 @@ type gameMonitor struct {
 
 func newGameMonitor(
 	logger log.Logger,
+	m metrics.Metricer,
 	cl clock.Clock,
 	source gameSource,
 	scheduler gameScheduler,
@@ -45,6 +48,7 @@ func newGameMonitor(
 ) *gameMonitor {
 	return &gameMonitor{
 		logger:           logger,
+		metrics:          m,
 		clock:            cl,
 		scheduler:        scheduler,
 		source:           source,

op-challenger/game/monitor_test.go

@@ -6,6 +6,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-node/testlog"
 	"github.com/ethereum-optimism/optimism/op-service/clock"
 	"github.com/ethereum/go-ethereum/common"
@@ -100,7 +101,7 @@ func setupMonitorTest(t *testing.T, allowedGames []common.Address) (*gameMonitor
 		return i, nil
 	}
 	sched := &stubScheduler{}
-	monitor := newGameMonitor(logger, clock.SystemClock, source, sched, time.Duration(0), fetchBlockNum, allowedGames)
+	monitor := newGameMonitor(logger, metrics.NoopMetrics, clock.SystemClock, source, sched, time.Duration(0), fetchBlockNum, allowedGames)
 	return monitor, source, sched
 }
 

op-challenger/game/service.go

@@ -72,10 +72,10 @@ func NewService(ctx context.Context, logger log.Logger, cfg *config.Config) (*Se
 		disk,
 		cfg.MaxConcurrency,
 		func(addr common.Address, dir string) (scheduler.GamePlayer, error) {
-			return fault.NewGamePlayer(ctx, logger, cfg, dir, addr, txMgr, client)
+			return fault.NewGamePlayer(ctx, logger, m, cfg, dir, addr, txMgr, client)
 		})
 
-	monitor := newGameMonitor(logger, cl, loader, sched, cfg.GameWindow, client.BlockNumber, cfg.GameAllowlist)
+	monitor := newGameMonitor(logger, m, cl, loader, sched, cfg.GameWindow, client.BlockNumber, cfg.GameAllowlist)
 
 	m.RecordInfo(version.SimpleWithMeta)
 	m.RecordUp()

op-challenger/metrics/metrics.go

@@ -20,6 +20,10 @@ type Metricer interface {
 
 	// Record Tx metrics
 	txmetrics.TxMetricer
+
+	RecordGameStep()
+	RecordGameMove()
+	RecordCannonExecutionTime(t float64)
 }
 
 type Metrics struct {
@@ -31,6 +35,10 @@ type Metrics struct {
 
 	info prometheus.GaugeVec
 	up   prometheus.Gauge
+
+	moves               prometheus.Counter
+	steps               prometheus.Counter
+	cannonExecutionTime prometheus.Histogram
 }
 
 var _ Metricer = (*Metrics)(nil)
@@ -58,6 +66,22 @@ func NewMetrics() *Metrics {
 			Name:      "up",
 			Help:      "1 if the op-challenger has finished starting up",
 		}),
+		moves: factory.NewCounter(prometheus.CounterOpts{
+			Namespace: Namespace,
+			Name:      "moves",
+			Help:      "Number of game moves made by the challenge agent",
+		}),
+		steps: factory.NewCounter(prometheus.CounterOpts{
+			Namespace: Namespace,
+			Name:      "steps",
+			Help:      "Number of game steps made by the challenge agent",
+		}),
+		cannonExecutionTime: factory.NewHistogram(prometheus.HistogramOpts{
+			Namespace: Namespace,
+			Name:      "cannon_execution_time",
+			Help:      "Time (in seconds) to execute cannon",
+			Buckets:   append([]float64{1.0, 10.0}, prometheus.ExponentialBuckets(30.0, 2.0, 14)...),
+		}),
 	}
 }
 
@@ -84,3 +108,15 @@ func (m *Metrics) RecordUp() {
 func (m *Metrics) Document() []opmetrics.DocumentedMetric {
 	return m.factory.Document()
 }
+
+func (m *Metrics) RecordGameMove() {
+	m.moves.Add(1)
+}
+
+func (m *Metrics) RecordGameStep() {
+	m.steps.Add(1)
+}
+
+func (m *Metrics) RecordCannonExecutionTime(t float64) {
+	m.cannonExecutionTime.Observe(t)
+}

op-challenger/metrics/noop.go

@@ -10,5 +10,8 @@ type noopMetrics struct {
 
 var NoopMetrics Metricer = new(noopMetrics)
 
-func (*noopMetrics) RecordInfo(version string) {}
-func (*noopMetrics) RecordUp()                 {}
+func (*noopMetrics) RecordInfo(version string)           {}
+func (*noopMetrics) RecordUp()                           {}
+func (*noopMetrics) RecordGameMove()                     {}
+func (*noopMetrics) RecordGameStep()                     {}
+func (*noopMetrics) RecordCannonExecutionTime(t float64) {}

op-e2e/e2eutils/disputegame/cannon_helper.go

@@ -5,6 +5,7 @@ import (
 	"path/filepath"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/trace/cannon"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-e2e/e2eutils/challenger"
 	"github.com/ethereum-optimism/optimism/op-node/rollup"
 	"github.com/ethereum-optimism/optimism/op-node/testlog"
@@ -40,7 +41,7 @@ func (g *CannonGameHelper) CreateHonestActor(ctx context.Context, rollupCfg *rol
 	opts = append(opts, options...)
 	cfg := challenger.NewChallengerConfig(g.t, l1Endpoint, opts...)
 	logger := testlog.Logger(g.t, log.LvlInfo).New("role", "CorrectTrace")
-	provider, err := cannon.NewTraceProvider(ctx, logger, cfg, l1Client, filepath.Join(cfg.Datadir, "honest"), g.addr)
+	provider, err := cannon.NewTraceProvider(ctx, logger, metrics.NoopMetrics, cfg, l1Client, filepath.Join(cfg.Datadir, "honest"), g.addr)
 	g.require.NoError(err, "create cannon trace provider")
 
 	return &HonestHelper{

op-e2e/e2eutils/disputegame/helper.go

@@ -14,6 +14,7 @@ import (
 	"github.com/ethereum-optimism/optimism/op-chain-ops/genesis"
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/trace/alphabet"
 	"github.com/ethereum-optimism/optimism/op-challenger/game/fault/trace/cannon"
+	"github.com/ethereum-optimism/optimism/op-challenger/metrics"
 	"github.com/ethereum-optimism/optimism/op-e2e/e2eutils/challenger"
 	"github.com/ethereum-optimism/optimism/op-e2e/e2eutils/transactions"
 	"github.com/ethereum-optimism/optimism/op-e2e/e2eutils/wait"
@@ -175,7 +176,7 @@ func (h *FactoryHelper) StartCannonGameWithCorrectRoot(ctx context.Context, roll
 		L2Claim:       challengedOutput.OutputRoot,
 		L2BlockNumber: challengedOutput.L2BlockNumber,
 	}
-	provider := cannon.NewTraceProviderFromInputs(testlog.Logger(h.t, log.LvlInfo).New("role", "CorrectTrace"), cfg, inputs, cfg.Datadir)
+	provider := cannon.NewTraceProviderFromInputs(testlog.Logger(h.t, log.LvlInfo).New("role", "CorrectTrace"), metrics.NoopMetrics, cfg, inputs, cfg.Datadir)
 	rootClaim, err := provider.Get(ctx, math.MaxUint64)
 	h.require.NoError(err, "Compute correct root hash")
 

op-program/host/prefetcher/prefetcher.go

@@ -58,14 +58,18 @@ func (p *Prefetcher) Hint(hint string) error {
 func (p *Prefetcher) GetPreimage(ctx context.Context, key common.Hash) ([]byte, error) {
 	p.logger.Trace("Pre-image requested", "key", key)
 	pre, err := p.kvStore.Get(key)
-	if errors.Is(err, kvstore.ErrNotFound) && p.lastHint != "" {
+	// Use a loop to keep retrying the prefetch as long as the key is not found
+	// This handles the case where the prefetch downloads a preimage, but it is then deleted unexpectedly
+	// before we get to read it.
+	for errors.Is(err, kvstore.ErrNotFound) && p.lastHint != "" {
 		hint := p.lastHint
-		p.lastHint = ""
 		if err := p.prefetch(ctx, hint); err != nil {
 			return nil, fmt.Errorf("prefetch failed: %w", err)
 		}
-		// Should now be available
-		return p.kvStore.Get(key)
+		pre, err = p.kvStore.Get(key)
+		if err != nil {
+			p.logger.Error("Fetched pre-images for last hint but did not find required key", "hint", hint, "key", key)
+		}
 	}
 	return pre, err
 }

op-program/host/prefetcher/prefetcher_test.go

@@ -306,6 +306,41 @@ func TestBadHints(t *testing.T) {
 	})
 }
 
+func TestRetryWhenNotAvailableAfterPrefetching(t *testing.T) {
+	rng := rand.New(rand.NewSource(123))
+	node := testutils.RandomData(rng, 30)
+	hash := crypto.Keccak256Hash(node)
+
+	_, l1Source, l2Cl, kv := createPrefetcher(t)
+	putsToIgnore := 2
+	kv = &unreliableKvStore{KV: kv, putsToIgnore: putsToIgnore}
+	prefetcher := NewPrefetcher(testlog.Logger(t, log.LvlInfo), l1Source, l2Cl, kv)
+
+	// Expect one call for each ignored put, plus one more request for when the put succeeds
+	for i := 0; i < putsToIgnore+1; i++ {
+		l2Cl.ExpectNodeByHash(hash, node, nil)
+	}
+	defer l2Cl.MockDebugClient.AssertExpectations(t)
+
+	oracle := l2.NewPreimageOracle(asOracleFn(t, prefetcher), asHinter(t, prefetcher))
+	result := oracle.NodeByHash(hash)
+	require.EqualValues(t, node, result)
+}
+
+type unreliableKvStore struct {
+	kvstore.KV
+	putsToIgnore int
+}
+
+func (s *unreliableKvStore) Put(k common.Hash, v []byte) error {
+	if s.putsToIgnore > 0 {
+		s.putsToIgnore--
+		return nil
+	}
+	println("storing")
+	return s.KV.Put(k, v)
+}
+
 type l2Client struct {
 	*testutils.MockL2Client
 	*testutils.MockDebugClient