From 3ab42db89432e964467be50e1d33a832a950a03e Mon Sep 17 00:00:00 2001 From: Jared Wasinger Date: Mon, 13 Nov 2023 20:40:13 +0800 Subject: [PATCH] re-add testlogger. add minimal adaption/copy of TerminalHandler format to testlog package. Make logfmt value formatting public from log package. --- internal/testlog/testlog.go | 182 ++++++++++++++++++++++++++++++++++-- log/format.go | 4 +- 2 files changed, 176 insertions(+), 10 deletions(-) diff --git a/internal/testlog/testlog.go b/internal/testlog/testlog.go index a3b7d0721b..7b669c2c58 100644 --- a/internal/testlog/testlog.go +++ b/internal/testlog/testlog.go @@ -18,24 +18,190 @@ package testlog import ( + "bytes" + "context" + "fmt" + "sync" "testing" "github.com/ethereum/go-ethereum/log" "golang.org/x/exp/slog" ) -type relay struct { - t *testing.T +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 +// 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 } -func (r *relay) Write(p []byte) (n int, err error) { - r.t.Logf(string(p)) - return len(p), nil +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 +} + +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 { - r := relay{t} - handler := log.TerminalHandlerWithLevel(&r, level, false) - return log.NewLogger(handler) + 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...) +} + +// terminalFormat formats a message similarly to the TerminalHandler 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 + }) + + attrs = append(h.attrs, attrs...) + + fmt.Fprintf(buf, "%s[%s] %s ", lvl, r.Time.Format(termTimeFormat), r.Message) + + for i, attr := range attrs { + if i != 0 { + buf.WriteByte(' ') + } + + rawVal := attr.Value.Any() + val := log.FormatLogfmtValue(rawVal, true) + + buf.WriteString(attr.Key) + buf.WriteByte('=') + buf.WriteString(val) + } + 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.terminalFormat(r)) + } + l.h.buf = nil } diff --git a/log/format.go b/log/format.go index a98c95847a..9266dceb63 100644 --- a/log/format.go +++ b/log/format.go @@ -98,7 +98,7 @@ func (h *terminalHandler) logfmt(buf *bytes.Buffer, r slog.Record, color int) { key := escapeString(attr.Key) rawVal := attr.Value.Any() - val := formatLogfmtValue(rawVal, true) + val := FormatLogfmtValue(rawVal, true) // 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? @@ -150,7 +150,7 @@ func formatShared(value interface{}) (result interface{}) { } // formatValue formats a value for serialization -func formatLogfmtValue(value interface{}, term bool) string { +func FormatLogfmtValue(value interface{}, term bool) string { if value == nil { return "nil" }