Merge pull request #6476 from ethereum-optimism/aj/execute-cannon

op-challenger: Execute cannon

op-challenger/fault/cannon/executor.go

@@ -5,30 +5,37 @@ import (
 	"errors"
 	"fmt"
 	"os"
+	"os/exec"
 	"path/filepath"
 	"regexp"
 	"strconv"
 
 	"github.com/ethereum-optimism/optimism/op-challenger/config"
+	oplog "github.com/ethereum-optimism/optimism/op-service/log"
 	"github.com/ethereum/go-ethereum/log"
 )
 
-const snapsDir = "snapshots"
+const (
+	snapsDir     = "snapshots"
+	preimagesDir = "snapshots"
+)
 
 var snapshotNameRegexp = regexp.MustCompile(`^[0-9]+\.json$`)
 
-const snapshotFrequency = 10_000
-
 type snapshotSelect func(logger log.Logger, dir string, absolutePreState string, i uint64) (string, error)
+type cmdExecutor func(ctx context.Context, l log.Logger, binary string, args ...string) error
 
 type Executor struct {
 	logger           log.Logger
 	l1               string
 	l2               string
 	cannon           string
+	server           string
 	absolutePreState string
 	dataDir          string
+	snapshotFreq     uint
 	selectSnapshot   snapshotSelect
+	cmdExecutor      cmdExecutor
 }
 
 func NewExecutor(logger log.Logger, cfg *config.Config) *Executor {
@@ -37,9 +44,12 @@ func NewExecutor(logger log.Logger, cfg *config.Config) *Executor {
 		l1:               cfg.L1EthRpc,
 		l2:               cfg.CannonL2,
 		cannon:           cfg.CannonBin,
+		server:           cfg.CannonServer,
 		absolutePreState: cfg.CannonAbsolutePreState,
 		dataDir:          cfg.CannonDatadir,
+		snapshotFreq:     cfg.CannonSnapshotFreq,
 		selectSnapshot:   findStartingSnapshot,
+		cmdExecutor:      runCmd,
 	}
 }
 
@@ -48,8 +58,35 @@ func (e *Executor) GenerateProof(ctx context.Context, dir string, i uint64) erro
 	if err != nil {
 		return fmt.Errorf("find starting snapshot: %w", err)
 	}
-	return fmt.Errorf("please execute cannon with --input %v --proof-at %v --proof-fmt %v/%v/%%d.json --snapshot-at %%%d --snapshot-fmt '%v/%v/%%d.json",
-		start, i, dir, proofsDir, snapshotFrequency, dir, snapsDir)
+	args := []string{
+		"run",
+		"--input", start,
+		"--proof-at", "=" + strconv.FormatUint(i, 10),
+		"--stop-at", "=" + strconv.FormatUint(i+1, 10),
+		"--proof-fmt", filepath.Join(dir, proofsDir, "%d.json"),
+		"--snapshot-at", "%" + strconv.FormatUint(uint64(e.snapshotFreq), 10),
+		"--snapshot-fmt", filepath.Join(e.dataDir, snapsDir, "%d.json"),
+		"--",
+		e.server,
+		"--l1", e.l1,
+		"--l2", e.l2,
+		"--datadir", filepath.Join(e.dataDir, preimagesDir),
+		// TODO(CLI-4240): Pass local game inputs (l1.head, l2.head, l2.claim etc)
+	}
+
+	e.logger.Info("Generating trace", "proof", i, "cmd", e.cannon, "args", args)
+	return e.cmdExecutor(ctx, e.logger.New("proof", i), e.cannon, args...)
+}
+
+func runCmd(ctx context.Context, l log.Logger, binary string, args ...string) error {
+	cmd := exec.CommandContext(ctx, binary, args...)
+	stdOut := oplog.NewWriter(l, log.LvlInfo)
+	defer stdOut.Close()
+	stdErr := oplog.NewWriter(l, log.LvlError)
+	defer stdErr.Close()
+	cmd.Stdout = stdOut
+	cmd.Stderr = stdErr
+	return cmd.Run()
 }
 
 // findStartingSnapshot finds the closest snapshot before the specified traceIndex in snapDir.

op-challenger/fault/cannon/executor_test.go

 package cannon
 
 import (
+	"context"
 	"fmt"
 	"os"
 	"path/filepath"
 	"testing"
+	"time"
 
+	"github.com/ethereum-optimism/optimism/op-challenger/config"
 	"github.com/ethereum-optimism/optimism/op-node/testlog"
+	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/log"
 	"github.com/stretchr/testify/require"
 )
 
 const execTestCannonPrestate = "/foo/pre.json"
 
+func TestGenerateProof(t *testing.T) {
+	input := "starting.json"
+	cfg := config.NewConfig("http://localhost:8888", common.Address{0xaa}, config.TraceTypeCannon, true, 5)
+	cfg.CannonDatadir = t.TempDir()
+	cfg.CannonAbsolutePreState = "pre.json"
+	cfg.CannonBin = "./bin/cannon"
+	cfg.CannonServer = "./bin/op-program"
+	cfg.CannonL2 = "http://localhost:9999"
+	cfg.CannonSnapshotFreq = 500
+
+	executor := NewExecutor(testlog.Logger(t, log.LvlInfo), &cfg)
+	executor.selectSnapshot = func(logger log.Logger, dir string, absolutePreState string, i uint64) (string, error) {
+		return input, nil
+	}
+	var binary string
+	var subcommand string
+	args := make(map[string]string)
+	executor.cmdExecutor = func(ctx context.Context, l log.Logger, b string, a ...string) error {
+		binary = b
+		subcommand = a[0]
+		for i := 1; i < len(a); i += 2 {
+			args[a[i]] = a[i+1]
+		}
+		return nil
+	}
+	err := executor.GenerateProof(context.Background(), cfg.CannonDatadir, 150_000_000)
+	require.NoError(t, err)
+	require.Equal(t, cfg.CannonBin, binary)
+	require.Equal(t, "run", subcommand)
+	require.Equal(t, input, args["--input"])
+	require.Equal(t, "=150000000", args["--proof-at"])
+	require.Equal(t, "=150000001", args["--stop-at"])
+	require.Equal(t, "%500", args["--snapshot-at"])
+	require.Equal(t, cfg.CannonServer, args["--"])
+	require.Equal(t, cfg.L1EthRpc, args["--l1"])
+	require.Equal(t, cfg.CannonL2, args["--l2"])
+	require.Equal(t, filepath.Join(cfg.CannonDatadir, preimagesDir), args["--datadir"])
+	require.Equal(t, filepath.Join(cfg.CannonDatadir, proofsDir, "%d.json"), args["--proof-fmt"])
+	require.Equal(t, filepath.Join(cfg.CannonDatadir, snapsDir, "%d.json"), args["--snapshot-fmt"])
+}
+
+func TestRunCmdLogsOutput(t *testing.T) {
+	bin := "/bin/echo"
+	if _, err := os.Stat(bin); err != nil {
+		t.Skip(bin, " not available", err)
+	}
+	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
+	defer cancel()
+	logger := testlog.Logger(t, log.LvlInfo)
+	logs := testlog.Capture(logger)
+	err := runCmd(ctx, logger, bin, "Hello World")
+	require.NoError(t, err)
+	require.NotNil(t, logs.FindLog(log.LvlInfo, "Hello World"))
+}
+
 func TestFindStartingSnapshot(t *testing.T) {
 	logger := testlog.Logger(t, log.LvlInfo)
 

op-node/testlog/capturing.go

@@ -11,6 +11,14 @@ type CapturingHandler struct {
 	Logs     []*log.Record
 }
 
+func Capture(l log.Logger) *CapturingHandler {
+	handler := &CapturingHandler{
+		Delegate: l.GetHandler(),
+	}
+	l.SetHandler(handler)
+	return handler
+}
+
 func (c *CapturingHandler) Log(r *log.Record) error {
 	c.Logs = append(c.Logs, r)
 	if c.Delegate != nil {

op-service/log/writer.go

+package log
+
+import (
+	"sync"
+
+	"github.com/ethereum/go-ethereum/log"
+)
+
+type Writer struct {
+	log     func(str string, ctx ...interface{})
+	lock    sync.Mutex
+	pending []byte
+}
+
+func NewWriter(l log.Logger, lvl log.Lvl) *Writer {
+	var logMethod func(str string, ctx ...interface{})
+	switch lvl {
+	case log.LvlTrace:
+		logMethod = l.Trace
+	case log.LvlDebug:
+		logMethod = l.Debug
+	case log.LvlInfo:
+		logMethod = l.Info
+	case log.LvlWarn:
+		logMethod = l.Warn
+	case log.LvlError:
+		logMethod = l.Error
+	case log.LvlCrit:
+		logMethod = l.Crit
+	default:
+		// Cast lvl to int to avoid trying to convert it to a string which will fail for unknown types
+		l.Error("Unknown log level. Using Error", "lvl", int(lvl))
+		logMethod = l.Error
+	}
+	return &Writer{
+		log: logMethod,
+	}
+}
+
+func (w *Writer) Write(b []byte) (int, error) {
+	w.lock.Lock()
+	defer w.lock.Unlock()
+	for _, c := range b {
+		if c == '\n' {
+			w.log(string(w.pending))
+			w.pending = nil
+			continue
+		}
+		w.pending = append(w.pending, c)
+	}
+	return len(b), nil
+}
+
+func (w *Writer) Close() error {
+	w.lock.Lock()
+	defer w.lock.Unlock()
+	if len(w.pending) > 0 {
+		w.log(string(w.pending))
+		w.pending = nil
+	}
+	return nil
+}

op-service/log/writer_test.go

+package log
+
+import (
+	"io"
+	"testing"
+
+	"github.com/ethereum-optimism/optimism/op-node/testlog"
+	"github.com/ethereum/go-ethereum/log"
+	"github.com/stretchr/testify/require"
+)
+
+var _ io.Writer = (*Writer)(nil)
+
+func TestLogWriter(t *testing.T) {
+	setup := func(t *testing.T, lvl log.Lvl) (*Writer, *testlog.CapturingHandler) {
+		logger := testlog.Logger(t, lvl)
+		logs := testlog.Capture(logger)
+		writer := NewWriter(logger, lvl)
+		return writer, logs
+	}
+
+	t.Run("LogSingleLine", func(t *testing.T) {
+		writer, logs := setup(t, log.LvlInfo)
+		line := []byte("Test line\n")
+		count, err := writer.Write(line)
+		require.NoError(t, err)
+		require.Equal(t, len(line), count)
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "Test line"))
+	})
+
+	t.Run("LogMultipleLines", func(t *testing.T) {
+		writer, logs := setup(t, log.LvlInfo)
+		line := []byte("Line 1\nLine 2\n")
+		count, err := writer.Write(line)
+		require.NoError(t, err)
+		require.Equal(t, len(line), count)
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "Line 1"))
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "Line 2"))
+	})
+
+	t.Run("LogLineAcrossMultipleCalls", func(t *testing.T) {
+		writer, logs := setup(t, log.LvlInfo)
+		line := []byte("First line\nSplit ")
+		count, err := writer.Write(line)
+		require.NoError(t, err)
+		require.Equal(t, len(line), count)
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "First line"))
+
+		line = []byte("Line\nLast Line\n")
+		count, err = writer.Write(line)
+		require.NoError(t, err)
+		require.Equal(t, len(line), count)
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "Split Line"))
+		require.NotNil(t, logs.FindLog(log.LvlInfo, "Last Line"))
+	})
+
+	// Can't test LvlCrit or it will call os.Exit
+	for _, lvl := range []log.Lvl{log.LvlTrace, log.LvlDebug, log.LvlInfo, log.LvlWarn, log.LvlError} {
+		lvl := lvl
+		t.Run("LogLvl_"+lvl.String(), func(t *testing.T) {
+			writer, logs := setup(t, lvl)
+			line := []byte("Log line\n")
+			count, err := writer.Write(line)
+			require.NoError(t, err)
+			require.Equal(t, len(line), count)
+			require.NotNil(t, logs.FindLog(lvl, "Log line"))
+		})
+	}
+
+	t.Run("UseErrorForUnknownLevels", func(t *testing.T) {
+		logger := testlog.Logger(t, log.LvlInfo)
+		logs := testlog.Capture(logger)
+		writer := NewWriter(logger, 60027)
+		line := []byte("Log line\n")
+		count, err := writer.Write(line)
+		require.NoError(t, err)
+		require.Equal(t, len(line), count)
+		require.NotNil(t, logs.FindLog(log.LvlError, "Unknown log level. Using Error"))
+		require.NotNil(t, logs.FindLog(log.LvlError, "Log line"))
+	})
+}