go-ethereum/internal/testlog/testlog_test.go
jwasinger f64aa6eaf7
internal/testlog: fix log output from sub-loggers (#31539)
When we instantiate a sub-logger via
`go-ethereum/internal/testlog/logger.With`, we copy the reference to the
`bufHandler` from the parent logger. However, internally,
`go-ethereum/internal/testlog/logger.With` calls `log/slog/Logger.With`
which creates a new handler instance (via
`internal/bufHandler.WithAttrs`).

This PR modifies sub-logger instantiation to use the newly-instantiated
handler, instead of copying the reference from the parent instance. The
type cast from `slog.Handler` to `*bufHandler` in
`internal/testlog/Logger.With` is safe here because a
`internal/testlog/Logger` can only be instantiated with a `*bufHandler`
as the underlying handler type.

Note, that I've also removed a pre-existing method that broke the above
assumption. However, this method is not used in our codebase.

I'm not sure if the assumption holds for forks of geth (e.g. optimism
has modified the testlogger somewhat allowing test loggers to accept
arbitrary handler types), but it seems okay to break API compatibility
given that this is in the `internal` package.

closes https://github.com/ethereum/go-ethereum/issues/31533
2025-04-10 18:21:32 +02:00

67 lines
1.5 KiB
Go

package testlog
import (
"bytes"
"fmt"
"io"
"strings"
"testing"
"github.com/ethereum/go-ethereum/log"
)
type mockT struct {
out io.Writer
}
func (t *mockT) Helper() {
// noop for the purposes of unit tests
}
func (t *mockT) Logf(format string, args ...any) {
// we could gate this operation in a mutex, but because testlogger
// only calls Logf with its internal mutex held, we just write output here
var lineBuf bytes.Buffer
if _, err := fmt.Fprintf(&lineBuf, format, args...); err != nil {
panic(err)
}
// The timestamp is locale-dependent, so we want to trim that off
// "INFO [01-01|00:00:00.000] a message ..." -> "a message..."
sanitized := strings.Split(lineBuf.String(), "]")[1]
if _, err := t.out.Write([]byte(sanitized)); err != nil {
panic(err)
}
}
func TestLogging(t *testing.T) {
tests := []struct {
name string
expected string
run func(t *mockT)
}{
{
"SubLogger",
` Visible
Hide and seek foobar=123
Also visible
`,
func(t *mockT) {
l := Logger(t, log.LevelInfo)
subLogger := l.New("foobar", 123)
l.Info("Visible")
subLogger.Info("Hide and seek")
l.Info("Also visible")
},
},
}
for _, tc := range tests {
outp := bytes.Buffer{}
mock := mockT{&outp}
tc.run(&mock)
if outp.String() != tc.expected {
fmt.Printf("output mismatch.\nwant: '%s'\ngot: '%s'\n", tc.expected, outp.String())
}
}
}