slogt is a bridge between Go stdlib testing pkg
and log/slog.
The problem: when tests execute, your slog output goes directly to stdout,
unlike a call to t.Log, which is correlated with your test's execution.
func TestSlog_Ugly(t *testing.T) {
log := slog.New(slog.NewTextHandler(os.Stdout, nil))
t.Log("I am indented correctly")
log.Info("But I am not")
}Produces:
=== RUN TestSlog_Ugly
slogt_test.go:22: I am indented correctly
time=2023-04-01T11:29:27.236-06:00 level=INFO msg="But I am not"
Note the second line (produced via slog).
slogt bridges those packages.
func TestSlogt_Pretty(t *testing.T) {
log := slogt.New(t)
t.Log("I am indented correctly")
log.Info("And so am I")
}Produces:
=== RUN TestSlogt_Pretty
slogt_test.go:28: I am indented correctly
logger.go:230: time=2023-04-01T11:33:06.342-06:00 level=INFO msg="And so am I"
Run go get as per procedure:
go get -u github.com/neilotoole/slogtThen, use slogt.New to get a *slog.Logger that you can
use as you normally would.
func TestText(t *testing.T) {
log := slogt.New(t)
log.Info("hello world")
}Produces:
=== RUN TestText
logger.go:230: time=2023-04-01T11:14:53.073-06:00 level=INFO msg="hello world"
In practice, you would pass the *slog.Logger returned from slogt.New to
the component under test. For example:
func TestApp(t *testing.T) {
log := slogt.New(t)
app := app.New(log, ...) // other dependencies
result, err := app.DepositMoney(100)
require.NoError(t, err)
require.Equal(t, 100, result.Balance)
}If the app.DepositMoney method logs anything, its output will be piped
to t.Log as desired.
The default output is text, i.e. a slog.TextHandler. You can
specify JSON using the slogt.JSON() option.
func TestJSON(t *testing.T) {
log := slogt.New(t, slogt.JSON())
log.Info("hello world")
}Produces:
=== RUN TestJSON
logger.go:230: {"time":"2023-04-01T11:14:12.164085-06:00","level":"INFO","msg":"hello world"}
To switch the default handler:
func init() {
slogt.DefaultHandler = slogt.JSON
}You can exercise full control over the handler using slogt.Factory().
func TestSomething(T *testing.T) {
// This factory returns a slog.Handler using slog.LevelError.
f := slogt.Factory(func(w io.Writer) slog.Handler {
opts := &slog.HandlerOptions{
Level: slog.LevelError,
}
return slog.NewTextHandler(w, opts)
})
log := slogt.New(t, f)
}Calling t.Log() prints the callsite as the first element
of each log statement (logger.go:230 in the example below).
=== RUN TestText
logger.go:230: time=2023-04-01T11:14:53.073-06:00 level=INFO msg="hello world"
But logger.go:230 is actually in the internals of slog package.
What we really want to see is the location of the caller of, say, log.Info().
Alas, given the available functionality
on testing.T (i.e. the Helper method), and how slog is implemented,
there's no way to have the correct callsite printed.
There are a number of ways this could be fixed:
- The Go team could implement a
testing.NewLogger(t)function that effectively does what this package does, but it would have access to thetesting.T's internal state, and so could manipulate the calldepth. - The
testing.Ttype could expose aHelperN(depth int)method that allows logging libraries and the like to manipulate the calldepth further. This would be generically useful even independent of this particular case. - The
slogpackage could test if the handler implements an interface with methodHelper(), and if so, invoke that method. This would need to be implemented in several spots inslogcodebase, and would introduce a little overhead.
Being that none of the above are available right now, we have to live with the incorrect callsite always being printed. If you also want to see the correct callsite alongside the incorrect one, you can do this:
func TestCaller(t *testing.T) {
f := slogt.Factory(func(w io.Writer) slog.Handler {
opts := &slog.HandlerOptions{
AddSource: true,
}
return slog.NewTextHandler(w, opts)
})
log := slogt.New(t, f)
log.Info("Show me the real callsite")
}Which produces (note the source attribute):
=== RUN TestCaller
logger.go:230: time=2023-04-01T11:21:49.896-06:00 level=INFO source=/Users/neilotoole/slogt/slogt_test.go:103 msg="Show me the real callsite"