all: replace log15 with slog (#28187)

This PR replaces Geth's logger package (a fork of [log15](https://github.com/inconshreveable/log15)) with an implementation using slog, a logging library included as part of the Go standard library as of Go1.21.

Main changes are as follows:
* removes any log handlers that were unused in the Geth codebase.
* Json, logfmt, and terminal formatters are now slog handlers.
* Verbosity level constants are changed to match slog constant values.  Internal translation is done to make this opaque to the user and backwards compatible with existing `--verbosity` and `--vmodule` options.
* `--log.backtraceat` and `--log.debug` are removed.

The external-facing API is largely the same as the existing Geth logger.  Logger method signatures remain unchanged.

A small semantic difference is that a `Handler` can only be set once per `Logger` and not changed dynamically.  This just means that a new logger must be instantiated every time the handler of the root logger is changed.

----
For users of the `go-ethereum/log` module. If you were using this module for your own project, you will need to change the initialization. If you previously did 
```golang
log.Root().SetHandler(log.LvlFilterHandler(log.LvlInfo, log.StreamHandler(os.Stderr, log.TerminalFormat(true))))
```
You now instead need to do 
```golang
log.SetDefault(log.NewLogger(log.NewTerminalHandlerWithLevel(os.Stderr, log.LevelInfo, true)))
```
See more about reasoning here: https://github.com/ethereum/go-ethereum/issues/28558#issuecomment-1820606613
This commit is contained in:
jwasinger
2023-11-29 08:33:50 +01:00
committed by GitHub
parent 61b844f2b2
commit 28e7371701
45 changed files with 968 additions and 1801 deletions
+2 -7
View File
@@ -37,6 +37,7 @@ import (
"github.com/ethereum/go-ethereum/log"
"github.com/hashicorp/go-bexpr"
"golang.org/x/exp/slog"
)
// Handler is the global debugging handler.
@@ -56,7 +57,7 @@ type HandlerT struct {
// Verbosity sets the log verbosity ceiling. The verbosity of individual packages
// and source files can be raised using Vmodule.
func (*HandlerT) Verbosity(level int) {
glogger.Verbosity(log.Lvl(level))
glogger.Verbosity(slog.Level(level))
}
// Vmodule sets the log verbosity pattern. See package log for details on the
@@ -65,12 +66,6 @@ func (*HandlerT) Vmodule(pattern string) error {
return glogger.Vmodule(pattern)
}
// BacktraceAt sets the log backtrace location. See package log for details on
// the pattern syntax.
func (*HandlerT) BacktraceAt(location string) error {
return glogger.BacktraceAt(location)
}
// MemStats returns detailed runtime memory statistics.
func (*HandlerT) MemStats() *runtime.MemStats {
s := new(runtime.MemStats)
+56 -60
View File
@@ -34,6 +34,7 @@ import (
"github.com/mattn/go-colorable"
"github.com/mattn/go-isatty"
"github.com/urfave/cli/v2"
"golang.org/x/exp/slog"
"gopkg.in/natefinch/lumberjack.v2"
)
@@ -75,17 +76,6 @@ var (
Usage: "Write logs to a file",
Category: flags.LoggingCategory,
}
backtraceAtFlag = &cli.StringFlag{
Name: "log.backtrace",
Usage: "Request a stack trace at a specific logging statement (e.g. \"block.go:271\")",
Value: "",
Category: flags.LoggingCategory,
}
debugFlag = &cli.BoolFlag{
Name: "log.debug",
Usage: "Prepends log messages with call-site location (file and line number)",
Category: flags.LoggingCategory,
}
logRotateFlag = &cli.BoolFlag{
Name: "log.rotate",
Usage: "Enables log file rotation",
@@ -160,8 +150,6 @@ var Flags = []cli.Flag{
verbosityFlag,
logVmoduleFlag,
vmoduleFlag,
backtraceAtFlag,
debugFlag,
logjsonFlag,
logFormatFlag,
logFileFlag,
@@ -180,45 +168,34 @@ var Flags = []cli.Flag{
}
var (
glogger *log.GlogHandler
logOutputStream log.Handler
glogger *log.GlogHandler
logOutputFile io.WriteCloser
defaultTerminalHandler *log.TerminalHandler
)
func init() {
glogger = log.NewGlogHandler(log.StreamHandler(os.Stderr, log.TerminalFormat(false)))
defaultTerminalHandler = log.NewTerminalHandler(os.Stderr, false)
glogger = log.NewGlogHandler(defaultTerminalHandler)
glogger.Verbosity(log.LvlInfo)
log.Root().SetHandler(glogger)
log.SetDefault(log.NewLogger(glogger))
}
func ResetLogging() {
if defaultTerminalHandler != nil {
defaultTerminalHandler.ResetFieldPadding()
}
}
// Setup initializes profiling and logging based on the CLI flags.
// It should be called as early as possible in the program.
func Setup(ctx *cli.Context) error {
var (
logfmt log.Format
output = io.Writer(os.Stderr)
logFmtFlag = ctx.String(logFormatFlag.Name)
handler slog.Handler
terminalOutput = io.Writer(os.Stderr)
output io.Writer
logFmtFlag = ctx.String(logFormatFlag.Name)
)
switch {
case ctx.Bool(logjsonFlag.Name):
// Retain backwards compatibility with `--log.json` flag if `--log.format` not set
defer log.Warn("The flag '--log.json' is deprecated, please use '--log.format=json' instead")
logfmt = log.JSONFormat()
case logFmtFlag == "json":
logfmt = log.JSONFormat()
case logFmtFlag == "logfmt":
logfmt = log.LogfmtFormat()
case logFmtFlag == "", logFmtFlag == "terminal":
useColor := (isatty.IsTerminal(os.Stderr.Fd()) || isatty.IsCygwinTerminal(os.Stderr.Fd())) && os.Getenv("TERM") != "dumb"
if useColor {
output = colorable.NewColorableStderr()
}
logfmt = log.TerminalFormat(useColor)
default:
// Unknown log format specified
return fmt.Errorf("unknown log format: %v", ctx.String(logFormatFlag.Name))
}
var (
ostream = log.StreamHandler(output, logfmt)
logFile = ctx.String(logFileFlag.Name)
rotation = ctx.Bool(logRotateFlag.Name)
)
@@ -241,27 +218,55 @@ func Setup(ctx *cli.Context) error {
} else {
context = append(context, "location", filepath.Join(os.TempDir(), "geth-lumberjack.log"))
}
lumberWriter := &lumberjack.Logger{
logOutputFile = &lumberjack.Logger{
Filename: logFile,
MaxSize: ctx.Int(logMaxSizeMBsFlag.Name),
MaxBackups: ctx.Int(logMaxBackupsFlag.Name),
MaxAge: ctx.Int(logMaxAgeFlag.Name),
Compress: ctx.Bool(logCompressFlag.Name),
}
ostream = log.StreamHandler(io.MultiWriter(output, lumberWriter), logfmt)
output = io.MultiWriter(terminalOutput, logOutputFile)
} else if logFile != "" {
f, err := os.OpenFile(logFile, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644)
if err != nil {
var err error
if logOutputFile, err = os.OpenFile(logFile, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644); err != nil {
return err
}
ostream = log.StreamHandler(io.MultiWriter(output, f), logfmt)
output = io.MultiWriter(logOutputFile, terminalOutput)
context = append(context, "location", logFile)
} else {
output = terminalOutput
}
glogger.SetHandler(ostream)
switch {
case ctx.Bool(logjsonFlag.Name):
// Retain backwards compatibility with `--log.json` flag if `--log.format` not set
defer log.Warn("The flag '--log.json' is deprecated, please use '--log.format=json' instead")
handler = log.JSONHandler(output)
case logFmtFlag == "json":
handler = log.JSONHandler(output)
case logFmtFlag == "logfmt":
handler = log.LogfmtHandler(output)
case logFmtFlag == "", logFmtFlag == "terminal":
useColor := (isatty.IsTerminal(os.Stderr.Fd()) || isatty.IsCygwinTerminal(os.Stderr.Fd())) && os.Getenv("TERM") != "dumb"
if useColor {
terminalOutput = colorable.NewColorableStderr()
if logOutputFile != nil {
output = io.MultiWriter(logOutputFile, terminalOutput)
} else {
output = terminalOutput
}
}
handler = log.NewTerminalHandler(output, useColor)
default:
// Unknown log format specified
return fmt.Errorf("unknown log format: %v", ctx.String(logFormatFlag.Name))
}
glogger = log.NewGlogHandler(handler)
// logging
verbosity := ctx.Int(verbosityFlag.Name)
glogger.Verbosity(log.Lvl(verbosity))
verbosity := log.FromLegacyLevel(ctx.Int(verbosityFlag.Name))
glogger.Verbosity(verbosity)
vmodule := ctx.String(logVmoduleFlag.Name)
if vmodule == "" {
// Retain backwards compatibility with `--vmodule` flag if `--log.vmodule` not set
@@ -272,16 +277,7 @@ func Setup(ctx *cli.Context) error {
}
glogger.Vmodule(vmodule)
debug := ctx.Bool(debugFlag.Name)
if ctx.IsSet(debugFlag.Name) {
debug = ctx.Bool(debugFlag.Name)
}
log.PrintOrigins(debug)
backtrace := ctx.String(backtraceAtFlag.Name)
glogger.BacktraceAt(backtrace)
log.Root().SetHandler(glogger)
log.SetDefault(log.NewLogger(glogger))
// profiling, tracing
runtime.MemProfileRate = memprofilerateFlag.Value
@@ -341,8 +337,8 @@ func StartPProf(address string, withMetrics bool) {
func Exit() {
Handler.StopCPUProfile()
Handler.StopGoTrace()
if closer, ok := logOutputStream.(io.Closer); ok {
closer.Close()
if logOutputFile != nil {
logOutputFile.Close()
}
}
+92 -34
View File
@@ -18,26 +18,19 @@
package testlog
import (
"bytes"
"context"
"fmt"
"sync"
"testing"
"github.com/ethereum/go-ethereum/log"
"golang.org/x/exp/slog"
)
// Handler returns a log handler which logs to the unit test log of t.
func Handler(t *testing.T, level log.Lvl) log.Handler {
return log.LvlFilterHandler(level, &handler{t, log.TerminalFormat(false)})
}
type handler struct {
t *testing.T
fmt log.Format
}
func (h *handler) Log(r *log.Record) error {
h.t.Logf("%s", h.fmt.Format(r))
return nil
}
const (
termTimeFormat = "01-02|15:04:05.000"
)
// logger implements log.Logger such that all output goes to the unit test log via
// t.Logf(). All methods in between logger.Trace, logger.Debug, etc. are marked as test
@@ -51,27 +44,62 @@ type logger struct {
}
type bufHandler struct {
buf []*log.Record
fmt log.Format
buf []slog.Record
attrs []slog.Attr
level slog.Level
}
func (h *bufHandler) Log(r *log.Record) error {
func (h *bufHandler) Handle(_ context.Context, r slog.Record) error {
h.buf = append(h.buf, r)
return nil
}
// Logger returns a logger which logs to the unit test log of t.
func Logger(t *testing.T, level log.Lvl) log.Logger {
l := &logger{
t: t,
l: log.New(),
mu: new(sync.Mutex),
h: &bufHandler{fmt: log.TerminalFormat(false)},
}
l.l.SetHandler(log.LvlFilterHandler(level, l.h))
return l
func (h *bufHandler) Enabled(_ context.Context, lvl slog.Level) bool {
return lvl <= h.level
}
func (h *bufHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
records := make([]slog.Record, len(h.buf))
copy(records[:], h.buf[:])
return &bufHandler{
records,
append(h.attrs, attrs...),
h.level,
}
}
func (h *bufHandler) WithGroup(_ string) slog.Handler {
panic("not implemented")
}
// Logger returns a logger which logs to the unit test log of t.
func Logger(t *testing.T, level slog.Level) log.Logger {
handler := bufHandler{
[]slog.Record{},
[]slog.Attr{},
level,
}
return &logger{
t: t,
l: log.NewLogger(&handler),
mu: new(sync.Mutex),
h: &handler,
}
}
// LoggerWithHandler returns
func LoggerWithHandler(t *testing.T, handler slog.Handler) log.Logger {
var bh bufHandler
return &logger{
t: t,
l: log.NewLogger(handler),
mu: new(sync.Mutex),
h: &bh,
}
}
func (l *logger) Write(level slog.Level, msg string, ctx ...interface{}) {}
func (l *logger) Trace(msg string, ctx ...interface{}) {
l.t.Helper()
l.mu.Lock()
@@ -80,6 +108,14 @@ func (l *logger) Trace(msg string, ctx ...interface{}) {
l.flush()
}
func (l *logger) Log(level slog.Level, msg string, ctx ...interface{}) {
l.t.Helper()
l.mu.Lock()
defer l.mu.Unlock()
l.l.Log(level, msg, ctx...)
l.flush()
}
func (l *logger) Debug(msg string, ctx ...interface{}) {
l.t.Helper()
l.mu.Lock()
@@ -120,23 +156,45 @@ func (l *logger) Crit(msg string, ctx ...interface{}) {
l.flush()
}
func (l *logger) With(ctx ...interface{}) log.Logger {
return &logger{l.t, l.l.With(ctx...), l.mu, l.h}
}
func (l *logger) New(ctx ...interface{}) log.Logger {
return &logger{l.t, l.l.New(ctx...), l.mu, l.h}
return l.With(ctx...)
}
func (l *logger) GetHandler() log.Handler {
return l.l.GetHandler()
}
// terminalFormat formats a message similarly to the NewTerminalHandler in the log package.
// The difference is that terminalFormat does not escape messages/attributes and does not pad attributes.
func (h *bufHandler) terminalFormat(r slog.Record) string {
buf := &bytes.Buffer{}
lvl := log.LevelAlignedString(r.Level)
attrs := []slog.Attr{}
r.Attrs(func(attr slog.Attr) bool {
attrs = append(attrs, attr)
return true
})
func (l *logger) SetHandler(h log.Handler) {
l.l.SetHandler(h)
attrs = append(h.attrs, attrs...)
fmt.Fprintf(buf, "%s[%s] %s ", lvl, r.Time.Format(termTimeFormat), r.Message)
if length := len(r.Message); length < 40 {
buf.Write(bytes.Repeat([]byte{' '}, 40-length))
}
for _, attr := range attrs {
rawVal := attr.Value.Any()
fmt.Fprintf(buf, " %s=%s", attr.Key, log.FormatLogfmtValue(rawVal, true))
}
buf.WriteByte('\n')
return buf.String()
}
// flush writes all buffered messages and clears the buffer.
func (l *logger) flush() {
l.t.Helper()
for _, r := range l.h.buf {
l.t.Logf("%s", l.h.fmt.Format(r))
l.t.Logf("%s", l.h.terminalFormat(r))
}
l.h.buf = nil
}