move fieldPadding logic into terminalHandler. make TerminalFormat private member function of terminalHandler

This commit is contained in:
Jared Wasinger 2023-11-10 23:26:36 +08:00
parent 5beed9f75d
commit 32a47ad53b
12 changed files with 29 additions and 206 deletions

View file

@ -24,7 +24,6 @@ import (
"os" "os"
"strings" "strings"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common"
"github.com/ethereum/go-ethereum/common/hexutil" "github.com/ethereum/go-ethereum/common/hexutil"
"github.com/ethereum/go-ethereum/core" "github.com/ethereum/go-ethereum/core"
@ -34,6 +33,7 @@ import (
"github.com/ethereum/go-ethereum/rlp" "github.com/ethereum/go-ethereum/rlp"
"github.com/ethereum/go-ethereum/tests" "github.com/ethereum/go-ethereum/tests"
"github.com/urfave/cli/v2" "github.com/urfave/cli/v2"
"golang.org/x/exp/slog"
) )
type result struct { type result struct {

View file

@ -39,7 +39,6 @@ import (
"sync" "sync"
"time" "time"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/accounts" "github.com/ethereum/go-ethereum/accounts"
"github.com/ethereum/go-ethereum/accounts/keystore" "github.com/ethereum/go-ethereum/accounts/keystore"
"github.com/ethereum/go-ethereum/cmd/utils" "github.com/ethereum/go-ethereum/cmd/utils"
@ -59,6 +58,7 @@ import (
"github.com/ethereum/go-ethereum/p2p/nat" "github.com/ethereum/go-ethereum/p2p/nat"
"github.com/ethereum/go-ethereum/params" "github.com/ethereum/go-ethereum/params"
"github.com/gorilla/websocket" "github.com/gorilla/websocket"
"golang.org/x/exp/slog"
) )
var ( var (

View file

@ -49,7 +49,6 @@ func (c customQuotedStringer) String() string {
// logTest is an entry point which spits out some logs. This is used by testing // logTest is an entry point which spits out some logs. This is used by testing
// to verify expected outputs // to verify expected outputs
func logTest(ctx *cli.Context) error { func logTest(ctx *cli.Context) error {
log.ResetGlobalState()
{ // big.Int { // big.Int
ba, _ := new(big.Int).SetString("111222333444555678999", 10) // "111,222,333,444,555,678,999" 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" bb, _ := new(big.Int).SetString("-111222333444555678999", 10) // "-111,222,333,444,555,678,999"

View file

@ -34,8 +34,8 @@ import (
"github.com/mattn/go-colorable" "github.com/mattn/go-colorable"
"github.com/mattn/go-isatty" "github.com/mattn/go-isatty"
"github.com/urfave/cli/v2" "github.com/urfave/cli/v2"
"gopkg.in/natefinch/lumberjack.v2"
"golang.org/x/exp/slog" "golang.org/x/exp/slog"
"gopkg.in/natefinch/lumberjack.v2"
) )
var Memsize memsizeui.Handler var Memsize memsizeui.Handler

View file

@ -18,154 +18,24 @@
package testlog package testlog
import ( import (
"context"
"sync"
"testing" "testing"
"github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/log"
"golang.org/x/exp/slog" "golang.org/x/exp/slog"
) )
// logger implements log.Logger such that all output goes to the unit test log via type relay struct {
// 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 t *testing.T
l log.Logger
mu *sync.Mutex
h *bufHandler
} }
type bufHandler struct { func (r *relay) Write(p []byte) (n int, err error) {
buf []slog.Record r.t.Logf(string(p))
attrs []slog.Attr return len(p), nil
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")
} }
// Logger returns a logger which logs to the unit test log of t. // Logger returns a logger which logs to the unit test log of t.
func Logger(t *testing.T, level slog.Level) log.Logger { func Logger(t *testing.T, level slog.Level) log.Logger {
handler := bufHandler{ r := relay{t}
[]slog.Record{}, handler := log.TerminalHandlerWithLevel(&r, level, false)
[]slog.Attr{}, return log.NewLogger(handler)
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
} }

View file

@ -6,7 +6,6 @@ import (
"math/big" "math/big"
"reflect" "reflect"
"strconv" "strconv"
"sync"
"time" "time"
"unicode/utf8" "unicode/utf8"
@ -14,10 +13,6 @@ import (
"golang.org/x/exp/slog" "golang.org/x/exp/slog"
) )
const timeKey = "t"
const lvlKey = "lvl"
const msgKey = "msg"
const ( const (
timeFormat = "2006-01-02T15:04:05-0700" timeFormat = "2006-01-02T15:04:05-0700"
termTimeFormat = "01-02|15:04:05.000" termTimeFormat = "01-02|15:04:05.000"
@ -26,21 +21,6 @@ const (
termCtxMaxPadding = 40 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 { type Format interface {
Format(r slog.Record) []byte Format(r slog.Record) []byte
} }
@ -64,16 +44,7 @@ type TerminalStringer interface {
TerminalString() string TerminalString() string
} }
// TerminalFormat formats log records optimized for human readability on func (h *terminalHandler) TerminalFormat(r slog.Record, usecolor bool) []byte {
// 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 {
msg := escapeMessage(r.Message) msg := escapeMessage(r.Message)
var color = 0 var color = 0
if usecolor { if usecolor {
@ -106,18 +77,19 @@ func TerminalFormat(r slog.Record, commonAttrs []slog.Attr, usecolor bool) []byt
b.Write(bytes.Repeat([]byte{' '}, termMsgJust-length)) b.Write(bytes.Repeat([]byte{' '}, termMsgJust-length))
} }
// print the keys logfmt style // print the keys logfmt style
logfmt(b, commonAttrs, r, color, true) h.logfmt(b, r, color)
return b.Bytes() 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{} attrs := []slog.Attr{}
r.Attrs(func(attr slog.Attr) bool { r.Attrs(func(attr slog.Attr) bool {
attrs = append(attrs, attr) attrs = append(attrs, attr)
return true return true
}) })
attrs = append(commonAttrs, attrs...) attrs = append(h.attrs, attrs...)
for i, attr := range attrs { for i, attr := range attrs {
if i != 0 { 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 // 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? // TODO (jwasinger) above comment was from log15 code. what does it mean? check that key bytes are ascii characters?
fieldPaddingLock.RLock() padding := h.fieldPadding[key]
padding := fieldPadding[key]
fieldPaddingLock.RUnlock()
length := utf8.RuneCountInString(val) length := utf8.RuneCountInString(val)
if padding < length && length <= termCtxMaxPadding { if padding < length && length <= termCtxMaxPadding {
padding = length padding = length
h.fieldPadding[key] = padding
fieldPaddingLock.Lock()
fieldPadding[key] = padding
fieldPaddingLock.Unlock()
} }
if color > 0 { if color > 0 {
fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, key) fmt.Fprintf(buf, "\x1b[%dm%s\x1b[0m=", color, key)

View file

@ -110,6 +110,9 @@ type terminalHandler struct {
lvl slog.Level lvl slog.Level
useColor bool useColor bool
attrs []slog.Attr 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 // 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, lvl,
useColor, useColor,
[]slog.Attr{}, []slog.Attr{},
make(map[string]int),
} }
} }
func (h *terminalHandler) Handle(_ context.Context, r slog.Record) error { func (h *terminalHandler) Handle(_ context.Context, r slog.Record) error {
h.mu.Lock() h.mu.Lock()
defer h.mu.Unlock() defer h.mu.Unlock()
h.wr.Write(TerminalFormat(r, h.attrs, h.useColor)) h.wr.Write(h.TerminalFormat(r, h.useColor))
return nil return nil
} }
@ -159,6 +163,7 @@ func (h *terminalHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
h.lvl, h.lvl,
h.useColor, h.useColor,
append(h.attrs, attrs...), append(h.attrs, attrs...),
make(map[string]int),
} }
} }

View file

@ -5,6 +5,7 @@ import (
"os" "os"
"strings" "strings"
"testing" "testing"
"golang.org/x/exp/slog" "golang.org/x/exp/slog"
) )

View file

@ -18,7 +18,6 @@ package discover
import ( import (
"bytes" "bytes"
"context"
"crypto/ecdsa" "crypto/ecdsa"
crand "crypto/rand" crand "crypto/rand"
"encoding/binary" "encoding/binary"
@ -32,8 +31,6 @@ import (
"testing" "testing"
"time" "time"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/internal/testlog" "github.com/ethereum/go-ethereum/internal/testlog"
"github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/log"
"github.com/ethereum/go-ethereum/p2p/discover/v4wire" "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. // Prefix logs with node ID.
lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString()) lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString())
cfg.Log = testlog.LoggerWithHandler(t, log.FuncHandler(func(_ context.Context, r slog.Record) error { cfg.Log = testlog.Logger(t, log.LevelTrace).With("node-id", lprefix)
if r.Level <= log.LevelTrace {
return nil
}
t.Logf("%s %s", lprefix, log.TerminalFormat(r, false))
return nil
}))
// Listen. // Listen.
socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}}) socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}})

View file

@ -18,7 +18,6 @@ package discover
import ( import (
"bytes" "bytes"
"context"
"crypto/ecdsa" "crypto/ecdsa"
"encoding/binary" "encoding/binary"
"fmt" "fmt"
@ -28,8 +27,6 @@ import (
"testing" "testing"
"time" "time"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/internal/testlog" "github.com/ethereum/go-ethereum/internal/testlog"
"github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/log"
"github.com/ethereum/go-ethereum/p2p/discover/v5wire" "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. // Prefix logs with node ID.
lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString()) lprefix := fmt.Sprintf("(%s)", ln.ID().TerminalString())
cfg.Log = testlog.LoggerWithHandler(t, log.FuncHandler(func(_ context.Context, r slog.Record) error { cfg.Log = testlog.Logger(t, log.LevelTrace).With("node-id", lprefix)
if r.Level <= log.LevelTrace {
return nil
}
t.Logf("%s %s", lprefix, log.TerminalFormat(r, false))
return nil
}))
// Listen. // Listen.
socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}}) socket, err := net.ListenUDP("udp4", &net.UDPAddr{IP: net.IP{127, 0, 0, 1}})

View file

@ -21,12 +21,12 @@ import (
"encoding/json" "encoding/json"
"os" "os"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common"
"github.com/ethereum/go-ethereum/common/hexutil" "github.com/ethereum/go-ethereum/common/hexutil"
"github.com/ethereum/go-ethereum/internal/ethapi" "github.com/ethereum/go-ethereum/internal/ethapi"
"github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/log"
"github.com/ethereum/go-ethereum/signer/core/apitypes" "github.com/ethereum/go-ethereum/signer/core/apitypes"
"golang.org/x/exp/slog"
) )
type AuditLogger struct { type AuditLogger struct {

View file

@ -23,10 +23,10 @@ import (
"os" "os"
"testing" "testing"
"golang.org/x/exp/slog"
"github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/common"
"github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/log"
"github.com/mattn/go-colorable" "github.com/mattn/go-colorable"
"golang.org/x/exp/slog"
) )
func TestEncryption(t *testing.T) { func TestEncryption(t *testing.T) {