add log test

Signed-off-by: Daisuke Kanda <[email protected]>

log/slog.go

@@ -20,6 +20,18 @@ type RelayLogger struct {
 var relayLogger *RelayLogger
 
 func InitLogger(logLevel, format, output string) error {
+	// output
+	switch output {
+	case "stdout":
+		return InitLoggerWithWriter(logLevel, format, os.Stdout)
+	case "stderr":
+		return InitLoggerWithWriter(logLevel, format, os.Stderr)
+	default:
+		return errors.New("invalid log output")
+	}
+}
+
+func InitLoggerWithWriter(logLevel, format string, writer io.Writer) error {
 	// level
 	var slogLevel slog.Level
 	if err := slogLevel.UnmarshalText([]byte(logLevel)); err != nil {
@@ -30,17 +42,6 @@ func InitLogger(logLevel, format, output string) error {
 		AddSource: true,
 	}
 
-	// output
-	var writer io.Writer
-	switch output {
-	case "stdout":
-		writer = os.Stdout
-	case "stderr":
-		writer = os.Stderr
-	default:
-		return errors.New("invalid log output")
-	}
-
 	var slogLogger *slog.Logger
 	// format
 	switch format {
@@ -66,13 +67,19 @@ func InitLogger(logLevel, format, output string) error {
 }
 
 func (rl *RelayLogger) log(logLevel slog.Level, skipCallDepth int, msg string, args ...any) {
+	ctx := context.Background();
+	if !rl.Logger.Enabled(ctx, logLevel) {
+		return
+	}
+
 	var pcs [1]uintptr
 	runtime.Callers(2 + skipCallDepth, pcs[:]) // skip [Callers, this func, ...]
 
 	record := slog.NewRecord(time.Now(), logLevel, msg, pcs[0])
 	record.Add(args...)
 
-	_ = rl.Logger.Handler().Handle(context.Background(), record)
+	// note that official log function also ignores Handle() error
+	_ = rl.Logger.Handler().Handle(ctx, record)
 }
 
 func (rl *RelayLogger) error(skipCallDepth int, msg string, err error, otherArgs ...any) {
@@ -83,25 +90,14 @@ func (rl *RelayLogger) error(skipCallDepth int, msg string, err error, otherArgs
 	args = append(args, otherArgs...)
 
 	rl.log(slog.LevelError, 1 + skipCallDepth, msg, args...)
-	//rl.Logger.Error(msg, args...)
 }
 
 func (rl *RelayLogger) Error(msg string, err error, otherArgs ...any) {
 	rl.error(1, msg, err, otherArgs...)
-/*
-	err = withstack.WithStackDepth(err, 1)
-	var args []any
-	args = append(args, "error", err)
-	args = append(args, "stack", fmt.Sprintf("%+v", err))
-	args = append(args, otherArgs...)
-
-	rl.Logger.Error(msg, args...)
-*/
 }
 
 func (rl *RelayLogger) Fatal(msg string, err error, otherArgs ...any) {
 	rl.error(1, msg, err, otherArgs...)
-	//rl.Error(msg, err, otherArgs...)
 	panic(msg)
 }
 
@@ -219,15 +215,4 @@ func (rl *RelayLogger) TimeTrack(start time.Time, name string, otherArgs ...any)
 	elapsed := time.Since(start)
 	allArgs := append([]any{"name", name, "elapsed", elapsed.Nanoseconds()}, otherArgs...)
 	rl.log(slog.LevelInfo, 1, "time track", allArgs...)
-/*
-	var pcs [1]uintptr
-	runtime.Callers(2, pcs[:]) // skip [Callers, this func]
-	record := slog.NewRecord(time.Now(), slog.LevelInfo, "time track", pcs[0])
-
-	allArgs := append([]any{"name", name, "elapsed", elapsed.Nanoseconds()}, otherArgs...)
-	record.Add(allArgs...)
-
-	_ = rl.Logger.Handler().Handle(context.Background(), record)
-	//rl.Logger.Info("time track", allArgs...)
-*/
 }

log/slog_test.go

@@ -0,0 +1,97 @@
+package log
+
+import (
+	"testing"
+
+	"fmt"
+	"log/slog"
+	"bytes"
+	"encoding/json"
+	"regexp"
+)
+
+type setupType struct {
+	logger *RelayLogger
+	buffer bytes.Buffer
+}
+
+func beforeEach(t *testing.T) *setupType {
+	var r setupType
+
+	err := InitLoggerWithWriter("info", "json", &r.buffer)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	r.logger = GetLogger()
+
+	return &r
+}
+
+type logType struct {
+	Time string
+	Level string
+	Source struct {
+		Function string
+		File string
+		Line int
+	}
+	Msg string
+	Stack string
+	Error string
+}
+
+func parseResult(setup *setupType, t *testing.T) (string, logType) {
+	raw := setup.buffer.String()
+	var parsed logType
+
+	err := json.Unmarshal(setup.buffer.Bytes(), &parsed)
+	if err != nil {
+		t.Fatalf("fail to parse log: %v: %s", err, raw)
+	}
+
+	return raw, parsed
+}
+
+func TestLogLevel(t *testing.T) {
+	setup := beforeEach(t)
+
+	setup.logger.log(slog.LevelDebug, 0, "test")
+	if 0 < setup.buffer.Len() {
+		t.Fatalf("debug log is output: %s", setup.buffer.String())
+	}
+}
+
+func TestLogLog(t *testing.T) {
+	setup := beforeEach(t)
+
+	setup.logger.log(slog.LevelInfo, 0, "test")
+	raw, r := parseResult(setup, t)
+
+	if r.Level != "INFO" {
+		t.Fatalf("mismatch level: %s", raw)
+	}
+
+	if m, err := regexp.MatchString(`/log.TestLogLog$`, r.Source.Function); err != nil || !m {
+		t.Fatalf("mismatch source.function: %v", raw)
+	}
+}
+
+func TestLogError(t *testing.T) {
+	setup := beforeEach(t)
+
+	setup.logger.Error("testerr", fmt.Errorf("dummy"))
+	raw, r := parseResult(setup, t)
+
+	if r.Level != "ERROR" {
+		t.Fatalf("mismatch level: %s", raw)
+	}
+
+	if m, err := regexp.MatchString(`/log.TestLogError$`, r.Source.Function); err != nil || !m {
+		t.Fatalf("mismatch source.function: %v", raw)
+	}
+
+	if r.Error != "dummy" {
+		t.Fatalf("mismatch level: %s", raw)
+	}
+}