feat(op-acceptor): add extended logging

Author: serpixel

op-acceptor/Dockerfile

@@ -14,7 +14,7 @@ RUN just build
 
 FROM golang:1.23.5-alpine3.21
 
-RUN apk add --no-cache ca-certificates build-base
+RUN apk add --no-cache ca-certificates build-base git
 
 # Increase the proxy connect timeout to 60 seconds
 ENV GOPROXYCONNECTTIMEOUT=60s
@@ -27,6 +27,7 @@ ENV GOPATH="/go"
 ENV PATH="${GOPATH}/bin:${PATH}"
 
 WORKDIR /app
+
 RUN addgroup -S app && adduser -S app -G app && \
     mkdir -p /devnets && \
     chown -R app:app /devnets

op-acceptor/config.go

@@ -22,8 +22,9 @@ type Config struct {
 	AllowSkips      bool          // Allow tests to be skipped instead of failing when preconditions are not met
 	DefaultTimeout  time.Duration // Default timeout for individual tests, can be overridden by test config
 	LogDir          string        // Directory to store test logs
-
-	Log log.Logger
+	OutputTestLogs  bool          // Whether to output test logs to the console
+	TestLogLevel    string        // Log level to be used for the tests
+	Log             log.Logger
 }
 
 // NewConfig creates a new Config instance
@@ -72,6 +73,8 @@ func NewConfig(ctx *cli.Context, log log.Logger, testDir string, validatorConfig
 		RunOnce:         runOnce,
 		AllowSkips:      ctx.Bool(flags.AllowSkips.Name),
 		DefaultTimeout:  ctx.Duration(flags.DefaultTimeout.Name),
+		OutputTestLogs:  ctx.Bool(flags.OutputTestLogs.Name),
+		TestLogLevel:    ctx.String(flags.TestLogLevel.Name),
 		LogDir:          logDir,
 		Log:             log,
 	}, nil

op-acceptor/flags/flags.go

@@ -66,6 +66,18 @@ var (
 		EnvVars: opservice.PrefixEnvVar(EnvVarPrefix, "LOGDIR"),
 		Usage:   "Directory to store test logs. Defaults to 'logs' if not specified.",
 	}
+	TestLogLevel = &cli.StringFlag{
+		Name:    "test-log-level",
+		Value:   "info",
+		EnvVars: opservice.PrefixEnvVar(EnvVarPrefix, "TEST_LOG_LEVEL"),
+		Usage:   "Log level to be used for the tests. Defaults to 'info'.",
+	}
+	OutputTestLogs = &cli.BoolFlag{
+		Name:    "output-test-logs",
+		Value:   false,
+		EnvVars: opservice.PrefixEnvVar(EnvVarPrefix, "OUTPUT_TEST_LOGS"),
+		Usage:   "Output test logs to the console. Defaults to false.",
+	}
 )
 
 var requiredFlags = []cli.Flag{
@@ -80,6 +92,8 @@ var optionalFlags = []cli.Flag{
 	AllowSkips,
 	DefaultTimeout,
 	LogDir,
+	TestLogLevel,
+	OutputTestLogs,
 }
 var Flags []cli.Flag
 

op-acceptor/nat.go

@@ -76,14 +76,16 @@ func New(ctx context.Context, config *Config, version string, shutdownCallback f
 
 	// Create runner with registry
 	testRunner, err := runner.NewTestRunner(runner.Config{
-		Registry:    reg,
-		WorkDir:     config.TestDir,
-		Log:         config.Log,
-		TargetGate:  config.TargetGate,
-		GoBinary:    config.GoBinary,
-		AllowSkips:  config.AllowSkips,
-		NetworkName: networkName,
-		DevnetEnv:   env,
+		Registry:       reg,
+		WorkDir:        config.TestDir,
+		Log:            config.Log,
+		TargetGate:     config.TargetGate,
+		GoBinary:       config.GoBinary,
+		AllowSkips:     config.AllowSkips,
+		OutputTestLogs: config.OutputTestLogs,
+		TestLogLevel:   config.TestLogLevel,
+		NetworkName:    networkName,
+		DevnetEnv:      env,
 	})
 	if err != nil {
 		return nil, fmt.Errorf("failed to create test runner: %w", err)

op-acceptor/runner/runner.go

@@ -5,6 +5,7 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"io"
 	"net/url"
 	"os"
 	"os/exec"
@@ -93,30 +94,34 @@ type TestRunnerWithFileLogger interface {
 
 // runner struct implements TestRunner interface
 type runner struct {
-	registry    *registry.Registry
-	validators  []types.ValidatorMetadata
-	workDir     string // Directory for running tests
-	log         log.Logger
-	runID       string
-	goBinary    string              // Path to the Go binary
-	allowSkips  bool                // Whether to allow skipping tests when preconditions are not met
-	fileLogger  *logging.FileLogger // Logger for storing test results
-	networkName string              // Name of the network being tested
-	env         *env.DevnetEnv
-	tracer      trace.Tracer
+	registry       *registry.Registry
+	validators     []types.ValidatorMetadata
+	workDir        string // Directory for running tests
+	log            log.Logger
+	runID          string
+	goBinary       string              // Path to the Go binary
+	allowSkips     bool                // Whether to allow skipping tests when preconditions are not met
+	outputTestLogs bool                // Whether to output test logs to the console
+	testLogLevel   string              // Log level to be used for the tests
+	fileLogger     *logging.FileLogger // Logger for storing test results
+	networkName    string              // Name of the network being tested
+	env            *env.DevnetEnv
+	tracer         trace.Tracer
 }
 
 // Config holds configuration for creating a new runner
 type Config struct {
-	Registry    *registry.Registry
-	TargetGate  string
-	WorkDir     string
-	Log         log.Logger
-	GoBinary    string              // path to the Go binary
-	AllowSkips  bool                // Whether to allow skipping tests when preconditions are not met
-	FileLogger  *logging.FileLogger // Logger for storing test results
-	NetworkName string              // Name of the network being tested
-	DevnetEnv   *env.DevnetEnv
+	Registry       *registry.Registry
+	TargetGate     string
+	WorkDir        string
+	Log            log.Logger
+	GoBinary       string              // path to the Go binary
+	AllowSkips     bool                // Whether to allow skipping tests when preconditions are not met
+	OutputTestLogs bool                // Whether to output test logs to the console
+	TestLogLevel   string              // Log level to be used for the tests
+	FileLogger     *logging.FileLogger // Logger for storing test results
+	NetworkName    string              // Name of the network being tested
+	DevnetEnv      *env.DevnetEnv
 }
 
 // NewTestRunner creates a new test runner instance
@@ -352,27 +357,10 @@ func (r *runner) getTestKey(validator types.ValidatorMetadata) string {
 	return validator.FuncName
 }
 
-func (r *runner) isGitInstalled() error {
-	gitCmd := exec.Command("git", "version")
-	err := gitCmd.Run()
-	if err != nil {
-		return fmt.Errorf("git is not installed")
-	}
-	return nil
-}
-
 func isLocalPath(pkg string) bool {
 	return strings.HasPrefix(pkg, "./") || strings.HasPrefix(pkg, "/") || strings.HasPrefix(pkg, "../")
 }
 
-func isGitRemotePath(pkg string) bool {
-	return strings.HasPrefix(pkg, "git::") ||
-		strings.HasPrefix(pkg, "git@") ||
-		strings.Contains(pkg, "github.com/") ||
-		strings.Contains(pkg, "bitbucket.org/") ||
-		strings.Contains(pkg, "golang.org/")
-}
-
 // RunTest implements the TestRunner interface
 func (r *runner) RunTest(ctx context.Context, metadata types.ValidatorMetadata) (*types.TestResult, error) {
 	// Use defer and recover to catch panics and convert them to errors
@@ -401,7 +389,7 @@ func (r *runner) RunTest(ctx context.Context, metadata types.ValidatorMetadata)
 		}
 	}()
 
-	// Check if the path is available locally, otherwise check if git is installed
+	// Check if the path is available locally
 	if isLocalPath(metadata.Package) {
 		fullPath := filepath.Join(r.workDir, metadata.Package)
 		if _, statErr := os.Stat(fullPath); os.IsNotExist(statErr) {
@@ -412,15 +400,6 @@ func (r *runner) RunTest(ctx context.Context, metadata types.ValidatorMetadata)
 				Error:    fmt.Errorf("local package path does not exist: %s", fullPath),
 			}, nil
 		}
-	} else if isGitRemotePath(metadata.Package) {
-		if err := r.isGitInstalled(); err != nil {
-			r.log.Error("Git is not installed but required for remote package, failing test", "validator", metadata.ID, "package", metadata.Package)
-			return &types.TestResult{
-				Metadata: metadata,
-				Status:   types.TestStatusFail,
-				Error:    fmt.Errorf("git is not installed"),
-			}, nil
-		}
 	}
 
 	r.log.Info("Running validator", "validator", metadata.ID)
@@ -562,8 +541,16 @@ func (r *runner) runSingleTest(ctx context.Context, metadata types.ValidatorMeta
 	defer cleanup()
 
 	var stdout, stderr bytes.Buffer
-	cmd.Stdout = &stdout
-	cmd.Stderr = &stderr
+	if r.outputTestLogs {
+		stdoutLogger := &logWriter{logFn: func(msg string) { r.log.Info("Test output", "test", metadata.FuncName, "output", msg) }}
+		stderrLogger := &logWriter{logFn: func(msg string) { r.log.Error("Test error output", "test", metadata.FuncName, "error", msg) }}
+
+		cmd.Stdout = io.MultiWriter(&stdout, stdoutLogger)
+		cmd.Stderr = io.MultiWriter(&stderr, stderrLogger)
+	} else {
+		cmd.Stdout = &stdout
+		cmd.Stderr = &stderr
+	}
 
 	r.log.Info("Running test", "test", metadata.FuncName)
 	r.log.Debug("Running test command",
@@ -609,6 +596,7 @@ func (r *runner) runSingleTest(ctx context.Context, metadata types.ValidatorMeta
 
 	// If we couldn't parse the output for some reason, create a minimal failing result
 	if parsedResult == nil {
+		r.log.Error("test exited with non-zero exit code", "exitCode", cmd.ProcessState.ExitCode())
 		parsedResult = &types.TestResult{
 			Metadata: metadata,
 			Status:   types.TestStatusFail,
@@ -1210,16 +1198,16 @@ func (r *runner) testCommandContext(ctx context.Context, name string, arg ...str
 			r.log.Error("Failed to write env to temp file", "error", err)
 		}
 
-		env := append(
-			os.Environ(),
+		logLevelStr := r.testLogLevel
+		runEnv := append([]string{fmt.Sprintf("LOG_LEVEL=%s", logLevelStr)}, os.Environ()...)
+		runEnv = append(runEnv,
 			// override the env URL with the one from the temp file
 			fmt.Sprintf("%s=%s", env.EnvURLVar, envFile.Name()),
 			// override the control resolution scheme with the original one
 			fmt.Sprintf("%s=%s", env.EnvCtrlVar, url.Scheme),
-			// Set DEVNET_EXPECT_PRECONDITIONS_MET=true to make tests fail instead of skip when preconditions are not met
 			"DEVNET_EXPECT_PRECONDITIONS_MET=true",
 		)
-		cmd.Env = telemetry.InstrumentEnvironment(ctx, env)
+		cmd.Env = telemetry.InstrumentEnvironment(ctx, runEnv)
 	}
 	cleanup := func() {
 		if envFile != nil {
@@ -1233,3 +1221,22 @@ func (r *runner) testCommandContext(ctx context.Context, name string, arg ...str
 // Make sure the runner type implements both interfaces
 var _ TestRunner = &runner{}
 var _ TestRunnerWithFileLogger = &runner{}
+
+type logWriter struct {
+	logFn func(msg string)
+	buf   []byte
+}
+
+func (w *logWriter) Write(p []byte) (n int, err error) {
+	w.buf = append(w.buf, p...)
+	for {
+		idx := bytes.IndexByte(w.buf, '\n')
+		if idx == -1 {
+			break
+		}
+		line := w.buf[:idx]
+		w.logFn(string(line))
+		w.buf = w.buf[idx+1:]
+	}
+	return len(p), nil
+}