add tests for xlog [wip]

dmke · dmke · commit f259c316f495 · 2024-10-31T18:07:12.000+01:00
diff --git a/service/middleware/logging_test.go b/service/middleware/logging_test.go
@@ -27,6 +27,7 @@ func TestLogging(t *testing.T) {
 	log, err := xlog.New(
 		xlog.AsText(),
 		xlog.WriteTo(&buf),
+		xlog.WithSource(),
 		xlog.MockClock(time.Unix(1650000000, 0).UTC()),
 	)
 	require.NoError(t, err)
diff --git a/service/status_test.go b/service/status_test.go
@@ -63,6 +63,7 @@ func TestHandleStatus_withFailIO(t *testing.T) {
 	log, err := xlog.New(
 		xlog.AsText(),
 		xlog.WriteTo(&buf),
+		xlog.WithSource(),
 		xlog.MockClock(time.Unix(1650000000, 0).UTC()),
 	)
 	require.NoError(t, err)
diff --git a/xlog/attrs.go b/xlog/attrs.go
@@ -32,13 +32,13 @@ func (err ErrorValue) Value() slog.Value {
 
 // LogValue implements [slog.LogValuer].
 func (err ErrorValue) LogValue() slog.Value {
-	return slog.StringValue(err.Error())
+	return err.Value()
 }
 
 // Error constructs a first-class error log attribute.
 //
 // Not to be confused with (xlog.Logger).Error() or (log/slog).Error(),
 // which produce an error-level log message.
 func Error(err error) slog.Attr {
-	return slog.Any(ErrorKey, ErrorValue{err})
+	return Any(ErrorKey, ErrorValue{err})
 }
diff --git a/xlog/discard.go b/xlog/discard.go
@@ -1,6 +1,7 @@
 package xlog
 
 import (
+	"context"
 	"log/slog"
 	"os"
 )
@@ -16,9 +17,19 @@ func NewDiscard() Logger {
 	return &discard{}
 }
 
+var (
+	_ Logger       = (*discard)(nil)
+	_ slog.Handler = (*discard)(nil)
+)
+
 func (*discard) Debug(string, ...slog.Attr) {}
 func (*discard) Info(string, ...slog.Attr)  {}
 func (*discard) Warn(string, ...slog.Attr)  {}
 func (*discard) Error(string, ...slog.Attr) {}
 func (*discard) Fatal(string, ...slog.Attr) { os.Exit(1) }
 func (d *discard) With(...slog.Attr) Logger { return d }
+
+func (*discard) Enabled(context.Context, slog.Level) bool   { return false }
+func (*discard) Handle(context.Context, slog.Record) error  { return nil }
+func (d *discard) WithAttrs(attrs []slog.Attr) slog.Handler { return d }
+func (d *discard) WithGroup(name string) slog.Handler       { return d }
diff --git a/xlog/options.go b/xlog/options.go
@@ -1,6 +1,7 @@
 package xlog
 
 import (
+	"errors"
 	"io"
 	"log/slog"
 	"os"
@@ -16,12 +17,11 @@ import (
 type Option func(*options) error
 
 type options struct {
-	discard bool
-	output  io.Writer
-	color   bool
-	clock   internal.Clock
-	level   slog.Leveler
-	source  bool
+	output io.Writer
+	color  bool
+	clock  internal.Clock
+	level  slog.Leveler
+	source bool
 
 	buildHandler func(o *options) slog.Handler
 }
@@ -47,9 +47,15 @@ func LeveledString(s string) Option {
 	}
 }
 
+var ErrNilWriter = errors.New("invalid writer: nil")
+
 // WriteTo sets the output.
 func WriteTo(w io.Writer) Option {
 	return func(o *options) error {
+		if w == nil {
+			return ErrNilWriter
+		}
+
 		o.output = w
 		return nil
 	}
@@ -103,7 +109,9 @@ func AsText() Option {
 			opts := []slogor.OptionFn{
 				slogor.SetLevel(o.level.Level()),
 				slogor.SetTimeFormat("[15:04:05.000]"),
-				slogor.ShowSource(),
+			}
+			if o.source {
+				opts = append(opts, slogor.ShowSource())
 			}
 			if f, isFile := o.output.(*os.File); !isFile || !isatty.IsTerminal(f.Fd()) {
 				opts = append(opts, slogor.DisableColor())
@@ -118,7 +126,10 @@ func AsText() Option {
 // constructor.
 func Discard() Option {
 	return func(o *options) error {
-		o.discard = true
+		o.buildHandler = func(o *options) slog.Handler {
+			// the discard logger doesn't have any options
+			return &discard{}
+		}
 		return nil
 	}
 }
diff --git a/xlog/options_test.go b/xlog/options_test.go
@@ -0,0 +1,140 @@
+package xlog
+
+import (
+	"bytes"
+	"context"
+	"fmt"
+	"log/slog"
+	"runtime"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/suite"
+)
+
+func TestOptionSuite(t *testing.T) {
+	suite.Run(t, new(OptionSuite))
+}
+
+type OptionSuite struct {
+	suite.Suite
+	options
+}
+
+func (o *OptionSuite) SetupTest() {
+	o.level = slog.LevelDebug
+}
+
+func (o *OptionSuite) TestLeveled() {
+	err := Leveled(slog.LevelError)(&o.options)
+	o.Require().NoError(err)
+	o.Assert().Equal(slog.LevelError, o.level)
+
+	err = Leveled(slog.Level(999))(&o.options)
+	o.Require().NoError(err)
+	o.Assert().Equal(slog.Level(999), o.level)
+}
+
+func (o *OptionSuite) TestLeveledString_valid() {
+	for i, tt := range []struct {
+		input    string
+		expected slog.Level
+	}{
+		{"dbg", slog.LevelDebug},
+		{"debug", slog.LevelDebug},
+
+		{"", slog.LevelInfo},
+		{"info", slog.LevelInfo},
+		{"INFO", slog.LevelInfo},
+
+		{"WARN", slog.LevelWarn},
+		{"WARNING", slog.LevelWarn},
+
+		{"ERR", slog.LevelError},
+		{"ERROR", slog.LevelError},
+		{"FaTaL", slog.LevelError},
+	} {
+		o.level = slog.Level(100 + i)
+		err := LeveledString(tt.input)(&o.options)
+		o.Require().NoError(err)
+		o.Assert().Equal(tt.expected, o.level)
+	}
+}
+
+func (o *OptionSuite) TestLeveledString_invalid() {
+	o.level = slog.Level(100)
+	err := LeveledString("ifno")(&o.options)
+	o.Require().Equal(slog.Level(100), o.level)
+	o.Assert().EqualError(err, `unknown log level: "ifno"`)
+}
+
+func (o *OptionSuite) TestWriteTo() {
+	var buf bytes.Buffer
+	err := WriteTo(&buf)(&o.options)
+	o.Require().NoError(err)
+	o.Assert().Equal(&buf, o.output)
+
+	err = WriteTo(nil)(&o.options)
+	o.Assert().EqualError(err, "invalid writer: nil")
+}
+
+func (o *OptionSuite) TestMockClock() {
+	t := time.Now()
+	err := MockClock(t)(&o.options)
+	o.Require().NoError(err)
+	o.Require().NotNil(o.clock)
+	o.Assert().EqualValues(t, o.clock.Now())
+}
+
+func (o *OptionSuite) TestWithSource() {
+	err := WithSource()(&o.options)
+	o.Require().NoError(err)
+	o.Assert().True(o.source)
+}
+
+func (o *OptionSuite) TestColor() {
+	err := Color()(&o.options)
+	o.Require().NoError(err)
+	o.Assert().True(o.color)
+}
+
+func (o *OptionSuite) testBuildHandler(expectedLog string, opts ...Option) {
+	o.T().Helper()
+
+	var buf bytes.Buffer
+	o.output = &buf
+
+	for _, opt := range opts {
+		o.Require().NoError(opt(&o.options))
+	}
+	o.Require().NotNil(o.buildHandler)
+	h := o.buildHandler(&o.options)
+	o.Require().NotNil(h)
+
+	o.Assert().False(h.Enabled(context.Background(), -999))
+
+	pc, _, _, ok := runtime.Caller(1)
+	o.Require().True(ok)
+	err := h.Handle(context.Background(), slog.NewRecord(
+		time.Time{}, slog.LevelInfo, "test", pc,
+	))
+	o.Assert().NoError(err)
+	o.Assert().EqualValues(expectedLog, buf.String())
+}
+
+func (o *OptionSuite) TestAsJSON() {
+	o.testBuildHandler(`{"level":"INFO","msg":"test"}`+"\n", AsJSON())
+}
+
+func (o *OptionSuite) TestAsText() {
+	o.testBuildHandler("INFO test\n", AsText())
+
+	_, _, line, ok := runtime.Caller(0)
+	o.Require().True(ok)
+	msg := fmt.Sprintf("INFO options_test.go:%d test\n", line+3)
+	o.testBuildHandler(msg, WithSource(), AsText())
+}
+
+func (o *OptionSuite) TestDiscard() {
+	o.testBuildHandler("", Discard())
+}
diff --git a/xlog/xlog.go b/xlog/xlog.go
@@ -49,13 +49,14 @@ func New(opt ...Option) (Logger, error) {
 		}
 	}
 
-	// the discard logger doesn't require any further setup
-	if opts.discard {
-		return &discard{}, nil
-	}
-
 	// setup mock time
 	h := opts.buildHandler(&opts)
+
+	// skip a lot of overhead for the discard logger
+	if d, ok := h.(*discard); ok {
+		return d, nil
+	}
+
 	if opts.clock != nil {
 		h = &mockTimeHandler{
 			clock:   opts.clock,
@@ -111,13 +112,13 @@ func (log *logger) With(a ...slog.Attr) Logger {
 // "error" and "fatal". Other input will result in err not being nil.
 func ParseLevel(s string) (l slog.Level, err error) {
 	switch strings.ToLower(s) {
-	case "debug":
+	case "dbg", "debug":
 		l = slog.LevelDebug
 	case "info", "": // make the zero value useful
 		l = slog.LevelInfo
 	case "warn", "warning":
 		l = slog.LevelWarn
-	case "error", "fatal":
+	case "err", "error", "fatal":
 		l = slog.LevelError
 	default:
 		err = fmt.Errorf("unknown log level: %q", s)

Original file line number	Diff line number	Diff line change
`@@ -27,6 +27,7 @@ func TestLogging(t *testing.T) {`
`27`	`27`	`log, err := xlog.New(`
`28`	`28`	`xlog.AsText(),`
`29`	`29`	`xlog.WriteTo(&buf),`
	`30`	`+ xlog.WithSource(),`
`30`	`31`	`xlog.MockClock(time.Unix(1650000000, 0).UTC()),`
`31`	`32`	`)`
`32`	`33`	`require.NoError(t, err)`
Original file line number	Diff line number	Diff line change
`@@ -63,6 +63,7 @@ func TestHandleStatus_withFailIO(t *testing.T) {`
`63`	`63`	`log, err := xlog.New(`
`64`	`64`	`xlog.AsText(),`
`65`	`65`	`xlog.WriteTo(&buf),`
	`66`	`+ xlog.WithSource(),`
`66`	`67`	`xlog.MockClock(time.Unix(1650000000, 0).UTC()),`
`67`	`68`	`)`
`68`	`69`	`require.NoError(t, err)`
Original file line number	Diff line number	Diff line change
`@@ -32,13 +32,13 @@ func (err ErrorValue) Value() slog.Value {`
`32`	`32`
`33`	`33`	`// LogValue implements [slog.LogValuer].`
`34`	`34`	`func (err ErrorValue) LogValue() slog.Value {`
`35`		`- return slog.StringValue(err.Error())`
	`35`	`+ return err.Value()`
`36`	`36`	`}`
`37`	`37`
`38`	`38`	`// Error constructs a first-class error log attribute.`
`39`	`39`	`//`
`40`	`40`	`// Not to be confused with (xlog.Logger).Error() or (log/slog).Error(),`
`41`	`41`	`// which produce an error-level log message.`
`42`	`42`	`func Error(err error) slog.Attr {`
`43`		`- return slog.Any(ErrorKey, ErrorValue{err})`
	`43`	`+ return Any(ErrorKey, ErrorValue{err})`
`44`	`44`	`}`