op-challenger: Extract game monitor loop from Main method and add tests

Includes the relevant game addresson all log messages by creating a dedicated logger that automatically includes it.

op-challenger/challenger.go

@@ -3,7 +3,6 @@ package op_challenger
 import (
 	"context"
 	"fmt"
-	"time"
 
 	"github.com/ethereum-optimism/optimism/op-bindings/bindings"
 	"github.com/ethereum-optimism/optimism/op-challenger/config"
@@ -31,50 +30,20 @@ func Main(ctx context.Context, logger log.Logger, cfg *config.Config) error {
 		return fmt.Errorf("failed to bind the fault dispute game contract: %w", err)
 	}
 
+	gameLogger := logger.New("game", cfg.GameAddress)
 	loader := fault.NewLoader(contract)
-	responder, err := fault.NewFaultResponder(logger, txMgr, cfg.GameAddress)
+	responder, err := fault.NewFaultResponder(gameLogger, txMgr, cfg.GameAddress)
 	if err != nil {
 		return fmt.Errorf("failed to create the responder: %w", err)
 	}
 	trace := fault.NewAlphabetProvider(cfg.AlphabetTrace, uint64(cfg.GameDepth))
 
-	agent := fault.NewAgent(loader, cfg.GameDepth, trace, responder, cfg.AgreeWithProposedOutput, logger)
+	agent := fault.NewAgent(loader, cfg.GameDepth, trace, responder, cfg.AgreeWithProposedOutput, gameLogger)
 
-	caller, err := fault.NewFaultCallerFromBindings(cfg.GameAddress, client, logger)
+	caller, err := fault.NewFaultCallerFromBindings(cfg.GameAddress, client, gameLogger)
 	if err != nil {
 		return fmt.Errorf("failed to bind the fault contract: %w", err)
 	}
 
-	logger.Info("Monitoring fault dispute game", "game", cfg.GameAddress, "agreeWithOutput", cfg.AgreeWithProposedOutput)
-
-	for {
-		logger.Trace("Checking if actions are required", "game", cfg.GameAddress)
-		if err = agent.Act(ctx); err != nil {
-			logger.Error("Error when acting on game", "err", err)
-		}
-		if status, err := caller.GetGameStatus(ctx); err != nil {
-			logger.Warn("Unable to retrieve game status", "err", err)
-		} else if status != 0 {
-			var expectedStatus fault.GameStatus
-			if cfg.AgreeWithProposedOutput {
-				expectedStatus = fault.GameStatusChallengerWon
-			} else {
-				expectedStatus = fault.GameStatusDefenderWon
-			}
-			if expectedStatus == status {
-				logger.Info("Game won", "status", fault.GameStatusString(status))
-			} else {
-				logger.Error("Game lost", "status", fault.GameStatusString(status))
-			}
-			return nil
-		} else {
-			caller.LogGameInfo(ctx)
-		}
-		select {
-		case <-time.After(300 * time.Millisecond):
-		// Continue
-		case <-ctx.Done():
-			return ctx.Err()
-		}
-	}
+	return fault.MonitorGame(ctx, gameLogger, cfg.AgreeWithProposedOutput, agent, caller)
 }

op-challenger/fault/agent.go

@@ -17,8 +17,8 @@ type Agent struct {
 	log                     log.Logger
 }
 
-func NewAgent(loader Loader, maxDepth int, trace TraceProvider, responder Responder, agreeWithProposedOutput bool, log log.Logger) Agent {
-	return Agent{
+func NewAgent(loader Loader, maxDepth int, trace TraceProvider, responder Responder, agreeWithProposedOutput bool, log log.Logger) *Agent {
+	return &Agent{
 		solver:                  NewSolver(maxDepth, trace),
 		loader:                  loader,
 		responder:               responder,

op-challenger/fault/caller.go

@@ -20,14 +20,12 @@ type FaultDisputeGameCaller interface {
 type FaultCaller struct {
 	FaultDisputeGameCaller
 	log log.Logger
-	fdgAddr common.Address
 }
 
-func NewFaultCaller(fdgAddr common.Address, caller FaultDisputeGameCaller, log log.Logger) *FaultCaller {
+func NewFaultCaller(caller FaultDisputeGameCaller, log log.Logger) *FaultCaller {
 	return &FaultCaller{
 		caller,
 		log,
-		fdgAddr,
 	}
 }
 
@@ -39,7 +37,6 @@ func NewFaultCallerFromBindings(fdgAddr common.Address, client *ethclient.Client
 	return &FaultCaller{
 		caller,
 		log,
-		fdgAddr,
 	}, nil
 }
 
@@ -55,7 +52,7 @@ func (fc *FaultCaller) LogGameInfo(ctx context.Context) {
 		fc.log.Error("failed to get claim count", "err", err)
 		return
 	}
-	fc.log.Info("Game info", "addr", fc.fdgAddr, "claims", claimLen, "status", GameStatusString(status))
+	fc.log.Info("Game info", "claims", claimLen, "status", GameStatusString(status))
 }
 
 // GetGameStatus returns the current game status.

op-challenger/fault/caller_test.go

@@ -7,12 +7,10 @@ import (
 	"testing"
 
 	"github.com/ethereum/go-ethereum/accounts/abi/bind"
-	"github.com/ethereum/go-ethereum/common"
 	"github.com/stretchr/testify/require"
 )
 
 var (
-	testAddr = common.HexToAddress("0x1234567890123456789012345678901234567890")
 	errMock = errors.New("mock error")
 )
 
@@ -65,7 +63,7 @@ func TestFaultCaller_GetGameStatus(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			fc := NewFaultCaller(testAddr, test.caller, nil)
+			fc := NewFaultCaller(test.caller, nil)
 			status, err := fc.GetGameStatus(context.Background())
 			require.Equal(t, test.expectedStatus, status)
 			require.Equal(t, test.expectedErr, err)
@@ -100,7 +98,7 @@ func TestFaultCaller_GetClaimDataLength(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			fc := NewFaultCaller(testAddr, test.caller, nil)
+			fc := NewFaultCaller(test.caller, nil)
 			claimDataLen, err := fc.GetClaimDataLength(context.Background())
 			require.Equal(t, test.expectedClaimDataLen, claimDataLen)
 			require.Equal(t, test.expectedErr, err)

op-challenger/fault/monitor.go

+package fault
+
+import (
+	"context"
+	"time"
+
+	"github.com/ethereum/go-ethereum/log"
+)
+
+type GameInfo interface {
+	GetGameStatus(context.Context) (GameStatus, error)
+	LogGameInfo(ctx context.Context)
+}
+
+type Actor interface {
+	Act(ctx context.Context) error
+}
+
+func MonitorGame(ctx context.Context, logger log.Logger, agreeWithProposedOutput bool, actor Actor, caller GameInfo) error {
+	logger.Info("Monitoring fault dispute game", "agreeWithOutput", agreeWithProposedOutput)
+
+	for {
+		done := progressGame(ctx, logger, agreeWithProposedOutput, actor, caller)
+		if done {
+			return nil
+		}
+		select {
+		case <-time.After(300 * time.Millisecond):
+		// Continue
+		case <-ctx.Done():
+			return ctx.Err()
+		}
+	}
+}
+
+// progressGame checks the current state of the game, and attempts to progress it by performing moves, steps or resolving
+// Returns true if the game is complete or false if it needs to be monitored further
+func progressGame(ctx context.Context, logger log.Logger, agreeWithProposedOutput bool, actor Actor, caller GameInfo) bool {
+	logger.Trace("Checking if actions are required")
+	if err := actor.Act(ctx); err != nil {
+		logger.Error("Error when acting on game", "err", err)
+	}
+	if status, err := caller.GetGameStatus(ctx); err != nil {
+		logger.Warn("Unable to retrieve game status", "err", err)
+	} else if status != 0 {
+		var expectedStatus GameStatus
+		if agreeWithProposedOutput {
+			expectedStatus = GameStatusChallengerWon
+		} else {
+			expectedStatus = GameStatusDefenderWon
+		}
+		if expectedStatus == status {
+			logger.Info("Game won", "status", GameStatusString(status))
+		} else {
+			logger.Error("Game lost", "status", GameStatusString(status))
+		}
+		return true
+	} else {
+		caller.LogGameInfo(ctx)
+	}
+	return false
+}

op-challenger/fault/monitor_test.go

+package fault
+
+import (
+	"context"
+	"errors"
+	"testing"
+
+	"github.com/ethereum-optimism/optimism/op-node/testlog"
+	"github.com/ethereum/go-ethereum/log"
+	"github.com/stretchr/testify/require"
+)
+
+func TestMonitorExitsWhenContextDone(t *testing.T) {
+	logger := testlog.Logger(t, log.LvlDebug)
+	actor := &stubActor{}
+	gameInfo := &stubGameInfo{}
+	ctx, cancel := context.WithCancel(context.Background())
+	cancel()
+	err := MonitorGame(ctx, logger, true, actor, gameInfo)
+	require.ErrorIs(t, err, context.Canceled)
+}
+
+func TestProgressGameAndLogState(t *testing.T) {
+	logger, _, actor, gameInfo := setupProgressGameTest(t)
+	done := progressGame(context.Background(), logger, true, actor, gameInfo)
+	require.False(t, done, "should not be done")
+	require.Equal(t, 1, actor.callCount, "should perform next actions")
+	require.Equal(t, 1, gameInfo.logCount, "should log latest game state")
+}
+
+func TestProgressGame_LogErrorFromAct(t *testing.T) {
+	logger, handler, actor, gameInfo := setupProgressGameTest(t)
+	actor.err = errors.New("Boom")
+	done := progressGame(context.Background(), logger, true, actor, gameInfo)
+	require.False(t, done, "should not be done")
+	require.Equal(t, 1, actor.callCount, "should perform next actions")
+	require.Equal(t, 1, gameInfo.logCount, "should log latest game state")
+	errLog := handler.FindLog(log.LvlError, "Error when acting on game")
+	require.NotNil(t, errLog, "should log error")
+	require.Equal(t, actor.err, errLog.GetContextValue("err"))
+}
+
+func TestProgressGame_LogErrorWhenGameLost(t *testing.T) {
+	tests := []struct {
+		name            string
+		status          GameStatus
+		agreeWithOutput bool
+		logLevel        log.Lvl
+		logMsg          string
+		statusText      string
+	}{
+		{
+			name:            "GameLostAsDefender",
+			status:          GameStatusChallengerWon,
+			agreeWithOutput: false,
+			logLevel:        log.LvlError,
+			logMsg:          "Game lost",
+			statusText:      "Challenger Won",
+		},
+		{
+			name:            "GameLostAsChallenger",
+			status:          GameStatusDefenderWon,
+			agreeWithOutput: true,
+			logLevel:        log.LvlError,
+			logMsg:          "Game lost",
+			statusText:      "Defender Won",
+		},
+		{
+			name:            "GameWonAsDefender",
+			status:          GameStatusDefenderWon,
+			agreeWithOutput: false,
+			logLevel:        log.LvlInfo,
+			logMsg:          "Game won",
+			statusText:      "Defender Won",
+		},
+		{
+			name:            "GameWonAsChallenger",
+			status:          GameStatusChallengerWon,
+			agreeWithOutput: true,
+			logLevel:        log.LvlInfo,
+			logMsg:          "Game won",
+			statusText:      "Challenger Won",
+		},
+	}
+	for _, test := range tests {
+		test := test
+		t.Run(test.name, func(t *testing.T) {
+			logger, handler, actor, gameInfo := setupProgressGameTest(t)
+			gameInfo.status = test.status
+
+			done := progressGame(context.Background(), logger, test.agreeWithOutput, actor, gameInfo)
+			require.True(t, done, "should be done")
+			require.Equal(t, 0, gameInfo.logCount, "should not log latest game state")
+			errLog := handler.FindLog(test.logLevel, test.logMsg)
+			require.NotNil(t, errLog, "should log game result")
+			require.Equal(t, test.statusText, errLog.GetContextValue("status"))
+		})
+	}
+}
+
+func setupProgressGameTest(t *testing.T) (log.Logger, *testlog.CapturingHandler, *stubActor, *stubGameInfo) {
+	logger := testlog.Logger(t, log.LvlDebug)
+	handler := &testlog.CapturingHandler{
+		Delegate: logger.GetHandler(),
+	}
+	logger.SetHandler(handler)
+	actor := &stubActor{}
+	gameInfo := &stubGameInfo{}
+	return logger, handler, actor, gameInfo
+}
+
+type stubActor struct {
+	callCount int
+	err       error
+}
+
+func (a *stubActor) Act(ctx context.Context) error {
+	a.callCount++
+	return a.err
+}
+
+type stubGameInfo struct {
+	status   GameStatus
+	err      error
+	logCount int
+}
+
+func (s *stubGameInfo) GetGameStatus(ctx context.Context) (GameStatus, error) {
+	return s.status, s.err
+}
+
+func (s *stubGameInfo) LogGameInfo(ctx context.Context) {
+	s.logCount++
+}

op-node/testlog/capturing.go

+package testlog
+
+import (
+	"github.com/ethereum/go-ethereum/log"
+)
+
+// CapturingHandler provides a log handler that captures all log records and optionally forwards them to a delegate.
+// Note that it is not thread safe.
+type CapturingHandler struct {
+	Delegate log.Handler
+	Logs     []*log.Record
+}
+
+func (c *CapturingHandler) Log(r *log.Record) error {
+	c.Logs = append(c.Logs, r)
+	if c.Delegate != nil {
+		return c.Delegate.Log(r)
+	}
+	return nil
+}
+
+func (c *CapturingHandler) Clear() {
+	c.Logs = nil
+}
+
+func (c *CapturingHandler) FindLog(lvl log.Lvl, msg string) *HelperRecord {
+	for _, record := range c.Logs {
+		if record.Lvl == lvl && record.Msg == msg {
+			return &HelperRecord{record}
+		}
+	}
+	return nil
+}
+
+type HelperRecord struct {
+	*log.Record
+}
+
+func (h *HelperRecord) GetContextValue(name string) any {
+	for i := 0; i < len(h.Ctx); i += 2 {
+		if h.Ctx[i] == name {
+			return h.Ctx[i+1]
+		}
+	}
+	return nil
+}
+
+var _ log.Handler = (*CapturingHandler)(nil)