diff --git a/cmd/evm/internal/t8ntool/transaction.go b/cmd/evm/internal/t8ntool/transaction.go index 1d43cd4846..a71af5141d 100644 --- a/cmd/evm/internal/t8ntool/transaction.go +++ b/cmd/evm/internal/t8ntool/transaction.go @@ -24,7 +24,6 @@ import ( "os" "strings" - "golang.org/x/exp/slog" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common/hexutil" "github.com/ethereum/go-ethereum/core" @@ -34,6 +33,7 @@ import ( "github.com/ethereum/go-ethereum/rlp" "github.com/ethereum/go-ethereum/tests" "github.com/urfave/cli/v2" + "golang.org/x/exp/slog" ) type result struct { diff --git a/cmd/faucet/faucet.go b/cmd/faucet/faucet.go index f9e3ad06d7..a8d570c61e 100644 --- a/cmd/faucet/faucet.go +++ b/cmd/faucet/faucet.go @@ -39,7 +39,6 @@ import ( "sync" "time" - "golang.org/x/exp/slog" "github.com/ethereum/go-ethereum/accounts" "github.com/ethereum/go-ethereum/accounts/keystore" "github.com/ethereum/go-ethereum/cmd/utils" @@ -59,6 +58,7 @@ import ( "github.com/ethereum/go-ethereum/p2p/nat" "github.com/ethereum/go-ethereum/params" "github.com/gorilla/websocket" + "golang.org/x/exp/slog" ) var ( diff --git a/cmd/geth/logtestcmd_active.go b/cmd/geth/logtestcmd_active.go index 0632f9ca4b..4addec0ac7 100644 --- a/cmd/geth/logtestcmd_active.go +++ b/cmd/geth/logtestcmd_active.go @@ -49,7 +49,6 @@ func (c customQuotedStringer) String() string { // logTest is an entry point which spits out some logs. This is used by testing // to verify expected outputs func logTest(ctx *cli.Context) error { - log.ResetGlobalState() { // big.Int ba, _ := new(big.Int).SetString("111222333444555678999", 10) // "111,222,333,444,555,678,999" bb, _ := new(big.Int).SetString("-111222333444555678999", 10) // "-111,222,333,444,555,678,999" diff --git a/internal/debug/flags.go b/internal/debug/flags.go index cc507685ad..796821160e 100644 --- a/internal/debug/flags.go +++ b/internal/debug/flags.go @@ -34,8 +34,8 @@ import ( "github.com/mattn/go-colorable" "github.com/mattn/go-isatty" "github.com/urfave/cli/v2" - "gopkg.in/natefinch/lumberjack.v2" "golang.org/x/exp/slog" + "gopkg.in/natefinch/lumberjack.v2" ) var Memsize memsizeui.Handler diff --git a/internal/testlog/testlog.go b/internal/testlog/testlog.go index 9bc6f4f579..a3b7d0721b 100644 --- a/internal/testlog/testlog.go +++ b/internal/testlog/testlog.go @@ -18,154 +18,24 @@ package testlog import ( - "context" - "sync" "testing" "github.com/ethereum/go-ethereum/log" "golang.org/x/exp/slog" ) -// 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 -// helpers, so the file and line number in unit test output correspond to the call site -// which emitted the log message. -type logger struct { - t *testing.T - l log.Logger - mu *sync.Mutex - h *bufHandler +type relay struct { + t *testing.T } -type bufHandler struct { - buf []slog.Record - attrs []slog.Attr - level slog.Level -} - -func (h *bufHandler) Handle(_ context.Context, r slog.Record) error { - h.buf = append(h.buf, r) - return nil -} - -func (h *bufHandler) Enabled(_ context.Context, lvl slog.Level) bool { - return lvl <= h.level -} - -// TODO: does testlogger make use of attrs? -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") +func (r *relay) Write(p []byte) (n int, err error) { + r.t.Logf(string(p)) + return len(p), nil } // 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) Handler() slog.Handler { - return l.l.Handler() -} - -func (l *logger) Trace(msg string, ctx ...interface{}) { - l.t.Helper() - l.mu.Lock() - defer l.mu.Unlock() - l.l.Trace(msg, ctx...) - 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() - defer l.mu.Unlock() - l.l.Debug(msg, ctx...) - l.flush() -} - -func (l *logger) Info(msg string, ctx ...interface{}) { - l.t.Helper() - l.mu.Lock() - defer l.mu.Unlock() - l.l.Info(msg, ctx...) - l.flush() -} - -func (l *logger) Warn(msg string, ctx ...interface{}) { - l.t.Helper() - l.mu.Lock() - defer l.mu.Unlock() - l.l.Warn(msg, ctx...) - l.flush() -} - -func (l *logger) Error(msg string, ctx ...interface{}) { - l.t.Helper() - l.mu.Lock() - defer l.mu.Unlock() - l.l.Error(msg, ctx...) - l.flush() -} - -func (l *logger) Crit(msg string, ctx ...interface{}) { - l.t.Helper() - l.mu.Lock() - defer l.mu.Unlock() - l.l.Crit(msg, ctx...) - 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 l.With(ctx...) -} - -// 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", log.TerminalFormat(r, false)) - } - l.h.buf = nil + r := relay{t} + handler := log.TerminalHandlerWithLevel(&r, level, false) + return log.NewLogger(handler) } diff --git a/log/format.go b/log/format.go index 057bbc32c1..a98c95847a 100644 --- a/log/format.go +++ b/log/format.go @@ -6,7 +6,6 @@ import ( "math/big" "reflect" "strconv" - "sync" "time" "unicode/utf8" @@ -14,10 +13,6 @@ import ( "golang.org/x/exp/slog" ) -const timeKey = "t" -const lvlKey = "lvl" -const msgKey = "msg" - const ( timeFormat = "2006-01-02T15:04:05-0700" termTimeFormat = "01-02|15:04:05.000" @@ -26,21 +21,6 @@ const ( termCtxMaxPadding = 40 ) -// ResetGlobalState resets the fieldPadding, which is useful for producing -// predictable output. -func ResetGlobalState() { - fieldPaddingLock.Lock() - fieldPadding = make(map[string]int) - fieldPaddingLock.Unlock() -} - -// fieldPadding is a global map with maximum field value lengths seen until now -// to allow padding log contexts in a bit smarter way. -var fieldPadding = make(map[string]int) - -// fieldPaddingLock is a global mutex protecting the field padding map. -var fieldPaddingLock sync.RWMutex - type Format interface { Format(r slog.Record) []byte } @@ -64,16 +44,7 @@ type TerminalStringer interface { TerminalString() string } -// TerminalFormat formats log records optimized for human readability on -// a terminal with color-coded level output and terser human friendly timestamp. -// This format should only be used for interactive programs or while developing. -// -// [LEVEL] [TIME] MESSAGE key=value key=value ... -// -// Example: -// -// [DBUG] [May 16 20:58:45] remove route ns=haproxy addr=127.0.0.1:50002 -func TerminalFormat(r slog.Record, commonAttrs []slog.Attr, usecolor bool) []byte { +func (h *terminalHandler) TerminalFormat(r slog.Record, usecolor bool) []byte { msg := escapeMessage(r.Message) var color = 0 if usecolor { @@ -106,18 +77,19 @@ func TerminalFormat(r slog.Record, commonAttrs []slog.Attr, usecolor bool) []byt b.Write(bytes.Repeat([]byte{' '}, termMsgJust-length)) } // print the keys logfmt style - logfmt(b, commonAttrs, r, color, true) + h.logfmt(b, r, color) + return b.Bytes() } -func logfmt(buf *bytes.Buffer, commonAttrs []slog.Attr, r slog.Record, color int, term bool) { +func (h *terminalHandler) logfmt(buf *bytes.Buffer, r slog.Record, color int) { attrs := []slog.Attr{} r.Attrs(func(attr slog.Attr) bool { attrs = append(attrs, attr) return true }) - attrs = append(commonAttrs, attrs...) + attrs = append(h.attrs, attrs...) for i, attr := range attrs { if i != 0 { @@ -130,17 +102,12 @@ func logfmt(buf *bytes.Buffer, commonAttrs []slog.Attr, r slog.Record, color int // XXX: we should probably check that all of your key bytes aren't invalid // TODO (jwasinger) above comment was from log15 code. what does it mean? check that key bytes are ascii characters? - fieldPaddingLock.RLock() - padding := fieldPadding[key] - fieldPaddingLock.RUnlock() + padding := h.fieldPadding[key] length := utf8.RuneCountInString(val) if padding < length && length <= termCtxMaxPadding { padding = length - - fieldPaddingLock.Lock() - fieldPadding[key] = padding - fieldPaddingLock.Unlock() + h.fieldPadding[key] = padding } if color > 0 { fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, key) diff --git a/log/handler.go b/log/handler.go index 4922366e43..68fd90fe8b 100644 --- a/log/handler.go +++ b/log/handler.go @@ -110,6 +110,9 @@ type terminalHandler struct { lvl slog.Level useColor bool attrs []slog.Attr + // fieldPadding is a map with maximum field value lengths seen until now + // to allow padding log contexts in a bit smarter way. + fieldPadding map[string]int } // TerminalHandler returns a handler which formats log records at all levels optimized for human readability on @@ -134,13 +137,14 @@ func TerminalHandlerWithLevel(wr io.Writer, lvl slog.Level, useColor bool) slog. lvl, useColor, []slog.Attr{}, + make(map[string]int), } } func (h *terminalHandler) Handle(_ context.Context, r slog.Record) error { h.mu.Lock() defer h.mu.Unlock() - h.wr.Write(TerminalFormat(r, h.attrs, h.useColor)) + h.wr.Write(h.TerminalFormat(r, h.useColor)) return nil } @@ -159,6 +163,7 @@ func (h *terminalHandler) WithAttrs(attrs []slog.Attr) slog.Handler { h.lvl, h.useColor, append(h.attrs, attrs...), + make(map[string]int), } } diff --git a/log/logger_test.go b/log/logger_test.go index 1b50e96110..bdf4a51eb4 100644 --- a/log/logger_test.go +++ b/log/logger_test.go @@ -5,6 +5,7 @@ import ( "os" "strings" "testing" + "golang.org/x/exp/slog" ) diff --git a/p2p/discover/v4_udp_test.go b/p2p/discover/v4_udp_test.go index 48bc014ee8..53ecb1bc6e 100644 --- a/p2p/discover/v4_udp_test.go +++ b/p2p/discover/v4_udp_test.go @@ -18,7 +18,6 @@ package discover import ( "bytes" - "context" "crypto/ecdsa" crand "crypto/rand" "encoding/binary" @@ -32,8 +31,6 @@ import ( "testing" "time" - "golang.org/x/exp/slog" - "github.com/ethereum/go-ethereum/internal/testlog" "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/p2p/discover/v4wire" @@ -560,14 +557,7 @@ func startLocalhostV4(t *testing.T, cfg Config) *UDPv4 { // Prefix logs with node ID. lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString()) - cfg.Log = testlog.LoggerWithHandler(t, log.FuncHandler(func(_ context.Context, r slog.Record) error { - if r.Level <= log.LevelTrace { - return nil - } - - t.Logf("%s %s", lprefix, log.TerminalFormat(r, false)) - return nil - })) + cfg.Log = testlog.Logger(t, log.LevelTrace).With("node-id", lprefix) // Listen. socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}}) diff --git a/p2p/discover/v5_udp_test.go b/p2p/discover/v5_udp_test.go index 8b6b6643ce..18d8aeac6d 100644 --- a/p2p/discover/v5_udp_test.go +++ b/p2p/discover/v5_udp_test.go @@ -18,7 +18,6 @@ package discover import ( "bytes" - "context" "crypto/ecdsa" "encoding/binary" "fmt" @@ -28,8 +27,6 @@ import ( "testing" "time" - "golang.org/x/exp/slog" - "github.com/ethereum/go-ethereum/internal/testlog" "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/p2p/discover/v5wire" @@ -82,13 +79,7 @@ func startLocalhostV5(t *testing.T, cfg Config) *UDPv5 { // Prefix logs with node ID. lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString()) - cfg.Log = testlog.LoggerWithHandler(t, log.FuncHandler(func(_ context.Context, r slog.Record) error { - if r.Level <= log.LevelTrace { - return nil - } - t.Logf("%s %s", lprefix, log.TerminalFormat(r, false)) - return nil - })) + cfg.Log = testlog.Logger(t, log.LevelTrace).With("node-id", lprefix) // Listen. socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}}) diff --git a/signer/core/auditlog.go b/signer/core/auditlog.go index 324f097033..d2207c9eb8 100644 --- a/signer/core/auditlog.go +++ b/signer/core/auditlog.go @@ -21,12 +21,12 @@ import ( "encoding/json" "os" - "golang.org/x/exp/slog" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common/hexutil" "github.com/ethereum/go-ethereum/internal/ethapi" "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/signer/core/apitypes" + "golang.org/x/exp/slog" ) type AuditLogger struct { diff --git a/signer/storage/aes_gcm_storage_test.go b/signer/storage/aes_gcm_storage_test.go index 9b3a17fce6..eb32a0a2a8 100644 --- a/signer/storage/aes_gcm_storage_test.go +++ b/signer/storage/aes_gcm_storage_test.go @@ -23,10 +23,10 @@ import ( "os" "testing" - "golang.org/x/exp/slog" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/log" "github.com/mattn/go-colorable" + "golang.org/x/exp/slog" ) func TestEncryption(t *testing.T) {