From fd324c00ae1f2e3e03d590627cbf92b21772e13c Mon Sep 17 00:00:00 2001
From: Googol Lee <i@googol.im>
Date: Tue, 23 Jul 2024 12:22:25 +0200
Subject: [PATCH] Add tests for log subpackage.

---
 log/examples_test.go |  77 +++++++++++++++++++++++++
 {mlog => log}/log.go |   2 +-
 log/log_test.go      | 131 +++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 209 insertions(+), 1 deletion(-)
 create mode 100644 log/examples_test.go
 rename {mlog => log}/log.go (99%)
 create mode 100644 log/log_test.go

diff --git a/log/examples_test.go b/log/examples_test.go
new file mode 100644
index 0000000..fc604fa
--- /dev/null
+++ b/log/examples_test.go
@@ -0,0 +1,77 @@
+package log_test
+
+import (
+	"context"
+	"log/slog"
+	"os"
+
+	"github.com/googollee/module"
+	"github.com/googollee/module/log"
+)
+
+func removeTimeAttr(groups []string, a slog.Attr) slog.Attr {
+	// Remove time from the output for predictable test output.
+	if a.Key == slog.TimeKey {
+		return slog.Attr{}
+	}
+
+	return a
+}
+
+func ExampleModule() {
+	loggerOption := slog.HandlerOptions{
+		AddSource:   false, // Remove code position from the output for predictable test output.
+		Level:       slog.LevelDebug,
+		ReplaceAttr: removeTimeAttr,
+	}
+
+	repo := module.NewRepo()
+	// repo.Add(log.TextLogger)) in common usage
+	// Provide a customed slog.Logger for predictable test output.
+	repo.Add(log.Module.ProvideValue(slog.New(slog.NewTextHandler(os.Stdout, &loggerOption))))
+
+	ctx, err := repo.InjectTo(context.Background())
+	if err != nil {
+		return
+	}
+
+	log.DEBUG(ctx, "debug")
+	log.INFO(ctx, "info")
+	log.WARN(ctx, "warning")
+	log.ERROR(ctx, "error")
+
+	// Output:
+	// level=DEBUG msg=debug
+	// level=INFO msg=info
+	// level=WARN msg=warning
+	// level=ERROR msg=error
+}
+
+func ExampleModule_withAttr() {
+	loggerOption := slog.HandlerOptions{
+		AddSource:   false, // Remove code position from the output for predictable test output.
+		ReplaceAttr: removeTimeAttr,
+	}
+
+	repo := module.NewRepo()
+	// repo.Add(log.TextLogger)) in common usage
+	// Provide a customed slog.Logger for predictable test output.
+	repo.Add(log.Module.ProvideValue(slog.New(slog.NewTextHandler(os.Stdout, &loggerOption))))
+
+	ctx, err := repo.InjectTo(context.Background())
+	if err != nil {
+		return
+	}
+
+	log.INFO(ctx, "before")
+	{
+		ctx := log.With(ctx, "span", "abc")
+		log.INFO(ctx, "in")
+	}
+	log.INFO(ctx, "after")
+
+	// Output:
+	// level=INFO msg=before
+	// level=INFO msg=in span=abc
+	// level=INFO msg=after
+}
diff --git a/mlog/log.go b/log/log.go
similarity index 99%
rename from mlog/log.go
rename to log/log.go
index 00328e0..805e91d 100644
--- a/mlog/log.go
+++ b/log/log.go
@@ -1,4 +1,4 @@
-package mlog
+package log
 
 import (
 	"context"
diff --git a/log/log_test.go b/log/log_test.go
new file mode 100644
index 0000000..d012c9b
--- /dev/null
+++ b/log/log_test.go
@@ -0,0 +1,131 @@
+package log_test
+
+import (
+	"bytes"
+	"context"
+	"io"
+	"log/slog"
+	"os"
+	"regexp"
+	"testing"
+
+	"github.com/googollee/module"
+	"github.com/googollee/module/log"
+)
+
+func captureStderr(t *testing.T, f func(t *testing.T)) string {
+	t.Helper()
+
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatal("create pipe error:", err)
+	}
+
+	orig := os.Stderr
+	os.Stderr = w
+
+	defer func() {
+		os.Stderr = orig
+		w.Close()
+	}()
+
+	f(t)
+
+	w.Close()
+
+	out, err := io.ReadAll(r)
+	if err != nil {
+		t.Fatal("read pipe error:", err)
+	}
+
+	return string(out)
+}
+
+func TestTextHandler(t *testing.T) {
+	output := captureStderr(t, func(t *testing.T) {
+		repo := module.NewRepo()
+		repo.Add(log.TextLogger)
+
+		ctx, err := repo.InjectTo(context.Background())
+		if err != nil {
+			t.Fatal("repo.InjectTo() error:", err)
+		}
+
+		log.ERROR(ctx, "log")
+	})
+
+	output = regexp.MustCompile("time=[^ ]*").ReplaceAllString(output, "time=<time>")
+
+	if got, want := output, "time=<time> level=ERROR msg=log\n"; got != want {
+		t.Errorf("\ngot : %q\nwant: %q", got, want)
+	}
+}
+
+func TestJSONHandler(t *testing.T) {
+	output := captureStderr(t, func(t *testing.T) {
+		repo := module.NewRepo()
+		repo.Add(log.JSONLogger)
+
+		ctx, err := repo.InjectTo(context.Background())
+		if err != nil {
+			t.Fatal("repo.InjectTo() error:", err)
+		}
+
+		log.ERROR(ctx, "log")
+	})
+
+	output = regexp.MustCompile(`"time":"[^"]*"`).ReplaceAllString(output, `"time":"<time>"`)
+
+	if got, want := output, "{\"time\":\"<time>\",\"level\":\"ERROR\",\"msg\":\"log\"}\n"; got != want {
+		t.Errorf("\ngot : %q\nwant: %q", got, want)
+	}
+}
+
+func TestNoInjection(t *testing.T) {
+	output := captureStderr(t, func(t *testing.T) {
+		ctx := context.Background()
+		log.DEBUG(ctx, "debug")
+		log.INFO(ctx, "info")
+		log.WARN(ctx, "warning")
+		log.ERROR(ctx, "error")
+
+		ctx = log.With(ctx, "span", "in_span")
+
+		log.DEBUG(ctx, "debug")
+		log.INFO(ctx, "info")
+		log.WARN(ctx, "warning")
+		log.ERROR(ctx, "error")
+	})
+
+	if got, want := output, ""; got != want {
+		t.Errorf("got: %q, want: %q", got, want)
+	}
+}
+
+func TestWithNoAttr(t *testing.T) {
+	var buf bytes.Buffer
+
+	loggerOption := slog.HandlerOptions{
+		AddSource:   false, // Remove code position from the output for predictable test output.
+		ReplaceAttr: removeTimeAttr,
+	}
+
+	repo := module.NewRepo()
+	repo.Add(log.Module.ProvideValue(slog.New(slog.NewTextHandler(&buf, &loggerOption))))
+
+	ctx, err := repo.InjectTo(context.Background())
+	if err != nil {
+		return
+	}
+
+	log.INFO(ctx, "before")
+	{
+		ctx := log.With(ctx)
+		log.INFO(ctx, "in")
+	}
+	log.INFO(ctx, "after")
+
+	if got, want := buf.String(), "level=INFO msg=before\nlevel=INFO msg=in\nlevel=INFO msg=after\n"; got != want {
+		t.Errorf("\ngot: %q\nwant: %q", got, want)
+	}
+}