Merge pull request #5085 from ethereum-optimism/jg/logger

op-node/service: Deduplicate logger + Better defaults

op-e2e/migration_test.go

@@ -12,6 +12,7 @@ import (
 	"time"
 
 	bss "github.com/ethereum-optimism/optimism/op-batcher/batcher"
+	"github.com/ethereum-optimism/optimism/op-node/chaincfg"
 	"github.com/ethereum-optimism/optimism/op-node/sources"
 	l2os "github.com/ethereum-optimism/optimism/op-proposer/proposer"
 	oplog "github.com/ethereum-optimism/optimism/op-service/log"
@@ -311,7 +312,9 @@ func TestMigration(t *testing.T) {
 		},
 		L1EpochPollInterval: 4 * time.Second,
 	}
-	rollupNode, err := node.New(ctx, rollupNodeConfig, log.New(), snapLog, "", metrics.NewMetrics(""))
+	rollupLog := log.New()
+	rollupNodeConfig.Rollup.LogDescription(rollupLog, chaincfg.L2ChainIDToNetworkName)
+	rollupNode, err := node.New(ctx, rollupNodeConfig, rollupLog, snapLog, "", metrics.NewMetrics(""))
 	require.NoError(t, err)
 
 	require.NoError(t, rollupNode.Start(ctx))

op-e2e/setup.go

@@ -26,6 +26,7 @@ import (
 	"github.com/ethereum-optimism/optimism/op-bindings/predeploys"
 	"github.com/ethereum-optimism/optimism/op-chain-ops/genesis"
 	"github.com/ethereum-optimism/optimism/op-e2e/e2eutils"
+	"github.com/ethereum-optimism/optimism/op-node/chaincfg"
 	"github.com/ethereum-optimism/optimism/op-node/eth"
 	"github.com/ethereum-optimism/optimism/op-node/metrics"
 	rollupNode "github.com/ethereum-optimism/optimism/op-node/node"
@@ -468,6 +469,8 @@ func (cfg SystemConfig) Start() (*System, error) {
 			}
 		}
 
+		c.Rollup.LogDescription(cfg.Loggers[name], chaincfg.L2ChainIDToNetworkName)
+
 		node, err := rollupNode.New(context.Background(), &c, cfg.Loggers[name], snapLog, "", metrics.NewMetrics(""))
 		if err != nil {
 			didErrAfterStart = true

op-node/cmd/main.go

@@ -8,6 +8,7 @@ import (
 	"strconv"
 	"syscall"
 
+	"github.com/ethereum-optimism/optimism/op-node/chaincfg"
 	"github.com/ethereum-optimism/optimism/op-node/cmd/doc"
 
 	"github.com/urfave/cli"
@@ -22,6 +23,7 @@ import (
 	"github.com/ethereum-optimism/optimism/op-node/metrics"
 	"github.com/ethereum-optimism/optimism/op-node/node"
 	"github.com/ethereum-optimism/optimism/op-node/version"
+	oplog "github.com/ethereum-optimism/optimism/op-service/log"
 	oppprof "github.com/ethereum-optimism/optimism/op-service/pprof"
 )
 
@@ -48,12 +50,7 @@ var VersionWithMeta = func() string {
 func main() {
 	// Set up logger with a default INFO level in case we fail to parse flags,
 	// otherwise the final critical log won't show what the parsing error was.
-	log.Root().SetHandler(
-		log.LvlFilterHandler(
-			log.LvlInfo,
-			log.StreamHandler(os.Stdout, log.TerminalFormat(true)),
-		),
-	)
+	oplog.SetupDefaults()
 
 	app := cli.NewApp()
 	app.Version = VersionWithMeta
@@ -85,12 +82,12 @@ func main() {
 
 func RollupNodeMain(ctx *cli.Context) error {
 	log.Info("Initializing Rollup Node")
-	logCfg, err := opnode.NewLogConfig(ctx)
-	if err != nil {
+	logCfg := oplog.ReadCLIConfig(ctx)
+	if err := logCfg.Check(); err != nil {
 		log.Error("Unable to create the log config", "error", err)
 		return err
 	}
-	log := logCfg.NewLogger()
+	log := oplog.NewLogger(logCfg)
 	m := metrics.NewMetrics("default")
 
 	cfg, err := opnode.NewConfig(ctx, log)
@@ -104,6 +101,13 @@ func RollupNodeMain(ctx *cli.Context) error {
 		return err
 	}
 
+	// Only pretty-print the banner if it is a terminal log. Other log it as key-value pairs.
+	if logCfg.Format == "terminal" {
+		log.Info("rollup config:\n" + cfg.Rollup.Description(chaincfg.L2ChainIDToNetworkName))
+	} else {
+		cfg.Rollup.LogDescription(log, chaincfg.L2ChainIDToNetworkName)
+	}
+
 	n, err := node.New(context.Background(), cfg, log, snapshotLog, VersionWithMeta, m)
 	if err != nil {
 		log.Error("Unable to create the rollup node", "error", err)

op-node/node/log.go

-package node
-
-import (
-	"fmt"
-	"os"
-	"strings"
-
-	"golang.org/x/term"
-
-	"github.com/ethereum/go-ethereum/log"
-)
-
-type LogConfig struct {
-	Level  string // Log level: trace, debug, info, warn, error, crit. Capitals are accepted too.
-	Color  bool   // Color the log output. Defaults to true if terminal is detected.
-	Format string // Format the log output. Supported formats: 'text', 'json'
-}
-
-func DefaultLogConfig() LogConfig {
-	return LogConfig{
-		Level:  "info",
-		Format: "text",
-		Color:  term.IsTerminal(int(os.Stdout.Fd())),
-	}
-}
-
-// Check verifes that the LogConfig is valid. Calls to `NewLogger` may fail if this
-// returns an error.
-func (cfg *LogConfig) Check() error {
-	switch cfg.Format {
-	case "json", "json-pretty", "terminal", "text":
-	default:
-		return fmt.Errorf("unrecognized log format: %s", cfg.Format)
-	}
-	level := strings.ToLower(cfg.Level) // ignore case
-	_, err := log.LvlFromString(level)
-	if err != nil {
-		return fmt.Errorf("unrecognized log level: %w", err)
-	}
-	return nil
-}
-
-// NewLogger creates a logger based on the supplied configuration
-func (cfg *LogConfig) NewLogger() log.Logger {
-	handler := log.StreamHandler(os.Stdout, format(cfg.Format, cfg.Color))
-	handler = log.SyncHandler(handler)
-	handler = log.LvlFilterHandler(level(cfg.Level), handler)
-	logger := log.New()
-	logger.SetHandler(handler)
-	return logger
-
-}
-
-// format turns a string and color into a structured Format object
-func format(lf string, color bool) log.Format {
-	switch lf {
-	case "json":
-		return log.JSONFormat()
-	case "json-pretty":
-		return log.JSONFormatEx(true, true)
-	case "text", "terminal":
-		return log.TerminalFormat(color)
-	default:
-		panic("Failed to create `log.Format` from options")
-	}
-}
-
-// level parses the level string into an appropriate object
-func level(s string) log.Lvl {
-	s = strings.ToLower(s) // ignore case
-	l, err := log.LvlFromString(s)
-	if err != nil {
-		panic(fmt.Sprintf("Could not parse log level: %v", err))
-	}
-	return l
-}

op-node/node/node.go

@@ -13,7 +13,6 @@ import (
 	"github.com/ethereum/go-ethereum/event"
 	"github.com/ethereum/go-ethereum/log"
 
-	"github.com/ethereum-optimism/optimism/op-node/chaincfg"
 	"github.com/ethereum-optimism/optimism/op-node/client"
 	"github.com/ethereum-optimism/optimism/op-node/eth"
 	"github.com/ethereum-optimism/optimism/op-node/metrics"
@@ -62,8 +61,6 @@ func New(ctx context.Context, cfg *Config, log log.Logger, snapshotLog log.Logge
 	// not a context leak, gossipsub is closed with a context.
 	n.resourcesCtx, n.resourcesClose = context.WithCancel(context.Background())
 
-	log.Info("rollup config:\n" + cfg.Rollup.Description(chaincfg.L2ChainIDToNetworkName))
-
 	err := n.init(ctx, cfg, snapshotLog)
 	if err != nil {
 		log.Error("Error initializing the rollup node", "err", err)

op-node/rollup/types.go

@@ -9,6 +9,7 @@ import (
 
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/ethereum/go-ethereum/core/types"
+	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/params"
 
 	"github.com/ethereum-optimism/optimism/op-node/eth"
@@ -271,6 +272,28 @@ func (c *Config) Description(l2Chains map[string]string) string {
 	return banner
 }
 
+// Description outputs a banner describing the important parts of rollup configuration in a log format.
+// Optionally provide a mapping of L2 chain IDs to network names to label the L2 chain with if not unknown.
+// The config should be config.Check()-ed before creating a description.
+func (c *Config) LogDescription(log log.Logger, l2Chains map[string]string) {
+	// Find and report the network the user is running
+	networkL2 := ""
+	if l2Chains != nil {
+		networkL2 = l2Chains[c.L2ChainID.String()]
+	}
+	if networkL2 == "" {
+		networkL2 = "unknown L2"
+	}
+	networkL1 := params.NetworkNames[c.L1ChainID.String()]
+	if networkL1 == "" {
+		networkL1 = "unknown L1"
+	}
+	log.Info("Rollup Config", "l2_chain_id", c.L2ChainID, "l2_network", networkL2, "l1_chain_id", c.L1ChainID,
+		"l1_network", networkL1, "l2_start_time", c.Genesis.L2Time, "l2_block_hash", c.Genesis.L2.Hash.String(),
+		"l2_block_number", c.Genesis.L2.Number, "l1_block_hash", c.Genesis.L1.Hash.String(),
+		"l1_block_number", c.Genesis.L1.Number, "regolith_time", fmtForkTimeOrUnset(c.RegolithTime))
+}
+
 func fmtForkTimeOrUnset(v *uint64) string {
 	if v == nil {
 		return "(not configured)"

op-node/service.go

@@ -168,21 +168,6 @@ func NewRollupConfig(ctx *cli.Context) (*rollup.Config, error) {
 	return &rollupConfig, nil
 }
 
-// NewLogConfig creates a log config from the provided flags or environment variables.
-func NewLogConfig(ctx *cli.Context) (node.LogConfig, error) {
-	cfg := node.DefaultLogConfig() // Done to set color based on terminal type
-	cfg.Level = ctx.GlobalString(flags.LogLevelFlag.Name)
-	cfg.Format = ctx.GlobalString(flags.LogFormatFlag.Name)
-	if ctx.IsSet(flags.LogColorFlag.Name) {
-		cfg.Color = ctx.GlobalBool(flags.LogColorFlag.Name)
-	}
-
-	if err := cfg.Check(); err != nil {
-		return cfg, err
-	}
-	return cfg, nil
-}
-
 func NewSnapshotLogger(ctx *cli.Context) (log.Logger, error) {
 	snapshotFile := ctx.GlobalString(flags.SnapshotLog.Name)
 	handler := log.DiscardHandler()

op-service/log/cli.go

@@ -28,13 +28,13 @@ func CLIFlags(envPrefix string) []cli.Flag {
 		},
 		cli.StringFlag{
 			Name:   FormatFlagName,
-			Usage:  "Format the log output. Supported formats: 'text', 'json'",
+			Usage:  "Format the log output. Supported formats: 'text', 'terminal', 'logfmt', 'json', 'json-pretty',",
 			Value:  "text",
 			EnvVar: opservice.PrefixEnvVar(envPrefix, "LOG_FORMAT"),
 		},
 		cli.BoolFlag{
 			Name:   ColorFlagName,
-			Usage:  "Color the log output",
+			Usage:  "Color the log output if in terminal mode",
 			EnvVar: opservice.PrefixEnvVar(envPrefix, "LOG_COLOR"),
 		},
 	}
@@ -43,12 +43,12 @@ func CLIFlags(envPrefix string) []cli.Flag {
 type CLIConfig struct {
 	Level  string // Log level: trace, debug, info, warn, error, crit. Capitals are accepted too.
 	Color  bool   // Color the log output. Defaults to true if terminal is detected.
-	Format string // Format the log output. Supported formats: 'text', 'json'
+	Format string // Format the log output. Supported formats: 'text', 'terminal', 'logfmt', 'json', 'json-pretty'
 }
 
 func (cfg CLIConfig) Check() error {
 	switch cfg.Format {
-	case "json", "json-pretty", "terminal", "text":
+	case "json", "json-pretty", "terminal", "text", "logfmt":
 	default:
 		return fmt.Errorf("unrecognized log format: %s", cfg.Format)
 	}
@@ -85,7 +85,9 @@ func ReadLocalCLIConfig(ctx *cli.Context) CLIConfig {
 	cfg := DefaultCLIConfig()
 	cfg.Level = ctx.String(LevelFlagName)
 	cfg.Format = ctx.String(FormatFlagName)
-	cfg.Color = ctx.Bool(ColorFlagName)
+	if ctx.IsSet(ColorFlagName) {
+		cfg.Color = ctx.Bool(ColorFlagName)
+	}
 	return cfg
 }
 
@@ -93,7 +95,9 @@ func ReadCLIConfig(ctx *cli.Context) CLIConfig {
 	cfg := DefaultCLIConfig()
 	cfg.Level = ctx.GlobalString(LevelFlagName)
 	cfg.Format = ctx.GlobalString(FormatFlagName)
-	cfg.Color = ctx.GlobalBool(ColorFlagName)
+	if ctx.IsSet(ColorFlagName) {
+		cfg.Color = ctx.GlobalBool(ColorFlagName)
+	}
 	return cfg
 }
 
@@ -104,8 +108,16 @@ func Format(lf string, color bool) log.Format {
 		return log.JSONFormat()
 	case "json-pretty":
 		return log.JSONFormatEx(true, true)
-	case "text", "terminal":
+	case "text":
+		if term.IsTerminal(int(os.Stdout.Fd())) {
+			return log.TerminalFormat(color)
+		} else {
+			return log.LogfmtFormat()
+		}
+	case "terminal":
 		return log.TerminalFormat(color)
+	case "logfmt":
+		return log.LogfmtFormat()
 	default:
 		panic("Failed to create `log.Format` from options")
 	}

op-service/log/defaults.go

@@ -10,7 +10,7 @@ func SetupDefaults() {
 	log.Root().SetHandler(
 		log.LvlFilterHandler(
 			log.LvlInfo,
-			log.StreamHandler(os.Stdout, log.TerminalFormat(true)),
+			log.StreamHandler(os.Stdout, log.LogfmtFormat()),
 		),
 	)
 }

ops-bedrock/docker-compose.yml

@@ -100,7 +100,6 @@ services:
       OP_PROPOSER_RESUBMISSION_TIMEOUT: 30s
       OP_PROPOSER_MNEMONIC: test test test test test test test test test test test junk
       OP_PROPOSER_L2_OUTPUT_HD_PATH: "m/44'/60'/0'/0/1"
-      OP_PROPOSER_LOG_TERMINAL: "true"
       OP_PROPOSER_L2OO_ADDRESS: "${L2OO_ADDRESS}"
       OP_PROPOSER_PPROF_ENABLED: "true"
       OP_PROPOSER_METRICS_ENABLED: "true"
@@ -134,7 +133,6 @@ services:
       OP_BATCHER_RESUBMISSION_TIMEOUT: 30s
       OP_BATCHER_MNEMONIC: test test test test test test test test test test test junk
       OP_BATCHER_SEQUENCER_HD_PATH: "m/44'/60'/0'/0/2"
-      OP_BATCHER_LOG_TERMINAL: "true"
       OP_BATCHER_PPROF_ENABLED: "true"
       OP_BATCHER_METRICS_ENABLED: "true"
       OP_BATCHER_RPC_ENABLE_ADMIN: "true"