Merge pull request #143 from wneessen/feature/142_implement-structured-json-logger

#142 Add structured JSON logger and associated tests

log/jsonlog.go

@@ -0,0 +1,82 @@
+// SPDX-FileCopyrightText: Copyright (c) 2023 The go-mail Authors
+//
+// SPDX-License-Identifier: MIT
+
+//go:build go1.21
+// +build go1.21
+
+package log
+
+import (
+	"fmt"
+	"io"
+	"log/slog"
+)
+
+// JSONlog is the default structured JSON logger that satisfies the Logger interface
+type JSONlog struct {
+	l   Level
+	log *slog.Logger
+}
+
+// NewJSON returns a new JSONlog type that satisfies the Logger interface
+func NewJSON(o io.Writer, l Level) *JSONlog {
+	lo := slog.HandlerOptions{}
+	switch l {
+	case LevelDebug:
+		lo.Level = slog.LevelDebug
+	case LevelInfo:
+		lo.Level = slog.LevelInfo
+	case LevelWarn:
+		lo.Level = slog.LevelWarn
+	case LevelError:
+		lo.Level = slog.LevelError
+	default:
+		lo.Level = slog.LevelDebug
+	}
+	lh := slog.NewJSONHandler(o, &lo)
+	return &JSONlog{
+		l:   l,
+		log: slog.New(lh),
+	}
+}
+
+// Debugf logs a debug message via the structured JSON logger
+func (l *JSONlog) Debugf(lo Log) {
+	if l.l >= LevelDebug {
+		l.log.WithGroup(DirString).With(
+			slog.String(DirFromString, lo.directionFrom()),
+			slog.String(DirToString, lo.directionTo()),
+		).Debug(fmt.Sprintf(lo.Format, lo.Messages...))
+	}
+}
+
+// Infof logs a info message via the structured JSON logger
+func (l *JSONlog) Infof(lo Log) {
+	if l.l >= LevelInfo {
+		l.log.WithGroup(DirString).With(
+			slog.String(DirFromString, lo.directionFrom()),
+			slog.String(DirToString, lo.directionTo()),
+		).Info(fmt.Sprintf(lo.Format, lo.Messages...))
+	}
+}
+
+// Warnf logs a warn message via the structured JSON logger
+func (l *JSONlog) Warnf(lo Log) {
+	if l.l >= LevelWarn {
+		l.log.WithGroup(DirString).With(
+			slog.String(DirFromString, lo.directionFrom()),
+			slog.String(DirToString, lo.directionTo()),
+		).Warn(fmt.Sprintf(lo.Format, lo.Messages...))
+	}
+}
+
+// Errorf logs a warn message via the structured JSON logger
+func (l *JSONlog) Errorf(lo Log) {
+	if l.l >= LevelError {
+		l.log.WithGroup(DirString).With(
+			slog.String(DirFromString, lo.directionFrom()),
+			slog.String(DirToString, lo.directionTo()),
+		).Error(fmt.Sprintf(lo.Format, lo.Messages...))
+	}
+}

log/jsonlog_test.go

@@ -0,0 +1,297 @@
+// SPDX-FileCopyrightText: Copyright (c) 2023 The go-mail Authors
+//
+// SPDX-License-Identifier: MIT
+
+//go:build go1.21
+// +build go1.21
+
+package log
+
+import (
+	"bytes"
+	"encoding/json"
+	"fmt"
+	"testing"
+	"time"
+)
+
+type jsonLog struct {
+	Direction jsonDir   `json:"direction"`
+	Level     string    `json:"level"`
+	Message   string    `json:"msg"`
+	Time      time.Time `json:"time"`
+}
+
+type jsonDir struct {
+	From string `json:"from"`
+	To   string `json:"to"`
+}
+
+func TestNewJSON(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, LevelDebug)
+	if l.l != LevelDebug {
+		t.Error("Expected level to be LevelDebug, got ", l.l)
+	}
+	if l.log == nil {
+		t.Error("logger not initialized")
+	}
+}
+
+func TestJSONDebugf(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, LevelDebug)
+	f := "test %s"
+	msg := "foo"
+	msg2 := "bar"
+
+	l.Debugf(Log{Direction: DirServerToClient, Format: f, Messages: []interface{}{msg}})
+	exFrom := "server"
+	exTo := "client"
+	jl, err := unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg, jl.Message)
+	}
+
+	b.Reset()
+	l.Debugf(Log{Direction: DirClientToServer, Format: f, Messages: []interface{}{msg2}})
+	exFrom = "client"
+	exTo = "server"
+	jl, err = unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg2) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg2, jl.Message)
+	}
+
+	b.Reset()
+	l.l = LevelInfo
+	l.Debugf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
+	if b.String() != "" {
+		t.Error("Debug message was not expected to be logged")
+	}
+}
+
+func TestJSONDebugf_WithDefault(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, 999)
+	f := "test %s"
+	msg := "foo"
+	msg2 := "bar"
+
+	l.Debugf(Log{Direction: DirServerToClient, Format: f, Messages: []interface{}{msg}})
+	exFrom := "server"
+	exTo := "client"
+	jl, err := unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg, jl.Message)
+	}
+
+	b.Reset()
+	l.Debugf(Log{Direction: DirClientToServer, Format: f, Messages: []interface{}{msg2}})
+	exFrom = "client"
+	exTo = "server"
+	jl, err = unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg2) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg2, jl.Message)
+	}
+
+	b.Reset()
+	l.l = LevelInfo
+	l.Debugf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
+	if b.String() != "" {
+		t.Error("Debug message was not expected to be logged")
+	}
+}
+
+func TestJSONInfof(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, LevelInfo)
+	f := "test %s"
+	msg := "foo"
+	msg2 := "bar"
+
+	l.Infof(Log{Direction: DirServerToClient, Format: f, Messages: []interface{}{msg}})
+	exFrom := "server"
+	exTo := "client"
+	jl, err := unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg, jl.Message)
+	}
+
+	b.Reset()
+	l.Infof(Log{Direction: DirClientToServer, Format: f, Messages: []interface{}{msg2}})
+	exFrom = "client"
+	exTo = "server"
+	jl, err = unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg2) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg2, jl.Message)
+	}
+
+	b.Reset()
+	l.l = LevelWarn
+	l.Infof(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
+	if b.String() != "" {
+		t.Error("Info message was not expected to be logged")
+	}
+}
+
+func TestJSONWarnf(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, LevelWarn)
+	f := "test %s"
+	msg := "foo"
+	msg2 := "bar"
+
+	l.Warnf(Log{Direction: DirServerToClient, Format: f, Messages: []interface{}{msg}})
+	exFrom := "server"
+	exTo := "client"
+	jl, err := unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg, jl.Message)
+	}
+
+	b.Reset()
+	l.Warnf(Log{Direction: DirClientToServer, Format: f, Messages: []interface{}{msg2}})
+	exFrom = "client"
+	exTo = "server"
+	jl, err = unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg2) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg2, jl.Message)
+	}
+
+	b.Reset()
+	l.l = LevelError
+	l.Warnf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
+	if b.String() != "" {
+		t.Error("Warn message was not expected to be logged")
+	}
+}
+
+func TestJSONErrorf(t *testing.T) {
+	var b bytes.Buffer
+	l := NewJSON(&b, LevelError)
+	f := "test %s"
+	msg := "foo"
+	msg2 := "bar"
+
+	l.Errorf(Log{Direction: DirServerToClient, Format: f, Messages: []interface{}{msg}})
+	exFrom := "server"
+	exTo := "client"
+	jl, err := unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg, jl.Message)
+	}
+
+	b.Reset()
+	l.Errorf(Log{Direction: DirClientToServer, Format: f, Messages: []interface{}{msg2}})
+	exFrom = "client"
+	exTo = "server"
+	jl, err = unmarshalLog(b.Bytes())
+	if err != nil {
+		t.Errorf("Debugf() failed, unmarshal json log message failed: %s", err)
+	}
+	if jl.Direction.To != exTo {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exTo, jl.Direction.To)
+	}
+	if jl.Direction.From != exFrom {
+		t.Errorf("Debugf() failed, expected message to: %s, got: %s", exFrom, jl.Direction.From)
+	}
+	if jl.Message != fmt.Sprintf(f, msg2) {
+		t.Errorf("Debugf() failed, expected message: %s, got %s", msg2, jl.Message)
+	}
+
+	b.Reset()
+	l.l = -99
+	l.Errorf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
+	if b.String() != "" {
+		t.Error("Error message was not expected to be logged")
+	}
+}
+
+func unmarshalLog(j []byte) (jsonLog, error) {
+	var jl jsonLog
+	if err := json.Unmarshal(j, &jl); err != nil {
+		return jl, err
+	}
+	return jl, nil
+}

log/log.go

@@ -21,6 +21,15 @@ const (
 	LevelDebug
 )
 
+const (
+	// DirString is a constant used for the structured logger
+	DirString = "direction"
+	// DirFromString is a constant used for the structured logger
+	DirFromString = "from"
+	// DirToString is a constant used for the structured logger
+	DirToString = "to"
+)
+
 // Direction is a type wrapper for the direction a debug log message goes
 type Direction int
 
@@ -51,3 +60,21 @@ func (l Log) directionPrefix() string {
 	}
 	return p
 }
+
+// directionFrom will return a from direction string depending on the Direction.
+func (l Log) directionFrom() string {
+	p := "server"
+	if l.Direction == DirClientToServer {
+		p = "client"
+	}
+	return p
+}
+
+// directionTo will return a to direction string depending on the Direction.
+func (l Log) directionTo() string {
+	p := "client"
+	if l.Direction == DirClientToServer {
+		p = "server"
+	}
+	return p
+}