internal/testlog: print file+line number of log call in test log (#20528)

* internal/testlog: print file+line number of log call in test log

This changes the unit test logger to print the actual file and line
number of the logging call instead of "testlog.go:44".

Output of 'go test -v -run TestServerListen ./p2p' before this change:

    === RUN   TestServerListen
    --- PASS: TestServerListen (0.00s)
        testlog.go:44: DEBUG[01-08|15:16:31.651] UDP listener up         addr=127.0.0.1:62678
        testlog.go:44: DEBUG[01-08|15:16:31.651] TCP listener up         addr=127.0.0.1:62678
        testlog.go:44: TRACE[01-08|15:16:31.652] Accepted connection     addr=127.0.0.1:62679

And after:

    === RUN   TestServerListen
    --- PASS: TestServerListen (0.00s)
        server.go:868: DEBUG[01-08|15:25:35.679] TCP listener up         addr=127.0.0.1:62712
        server.go:557: DEBUG[01-08|15:25:35.679] UDP listener up         addr=127.0.0.1:62712
        server.go:912: TRACE[01-08|15:25:35.680] Accepted connection     addr=127.0.0.1:62713

* internal/testlog: document use of t.Helper
This commit is contained in:
Felix Lange 2020-01-08 16:11:51 +01:00 committed by Péter Szilágyi
parent 4d663d57d6
commit 0218d7001d

View File

@ -18,18 +18,12 @@
package testlog
import (
"sync"
"testing"
"github.com/ethereum/go-ethereum/log"
)
// Logger returns a logger which logs to the unit test log of t.
func Logger(t *testing.T, level log.Lvl) log.Logger {
l := log.New()
l.SetHandler(Handler(t, level))
return l
}
// 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)})
@ -44,3 +38,105 @@ func (h *handler) Log(r *log.Record) error {
h.t.Logf("%s", h.fmt.Format(r))
return nil
}
// 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 bufHandler struct {
buf []*log.Record
fmt log.Format
}
func (h *bufHandler) Log(r *log.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 (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) 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) New(ctx ...interface{}) log.Logger {
return &logger{l.t, l.l.New(ctx...), l.mu, l.h}
}
func (l *logger) GetHandler() log.Handler {
return l.l.GetHandler()
}
func (l *logger) SetHandler(h log.Handler) {
l.l.SetHandler(h)
}
// 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.h.buf = nil
}