From 77d9e3d02ab0feb4ff8511456adf3c2a0059fa20 Mon Sep 17 00:00:00 2001 From: Winni Neessen Date: Wed, 23 Aug 2023 11:16:23 +0200 Subject: [PATCH] #142 Add structured JSON logger and associated tests This commit introduces a new type 'JSONlog' that satisfies the Logger interface for structured JSON logging. This includes new methods 'Debugf', 'Infof', 'Warnf' and 'Errorf' to log messages at different levels and an associated test 'jsonlog_test.go' to ensure correct functionality. This enhances the logging functionality by providing clarity in logs and eases debugging process. --- log/jsonlog.go | 82 ++++++++++++ log/jsonlog_test.go | 297 ++++++++++++++++++++++++++++++++++++++++++++ log/log.go | 27 ++++ 3 files changed, 406 insertions(+) create mode 100644 log/jsonlog.go create mode 100644 log/jsonlog_test.go diff --git a/log/jsonlog.go b/log/jsonlog.go new file mode 100644 index 0000000..c0b517e --- /dev/null +++ b/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...)) + } +} diff --git a/log/jsonlog_test.go b/log/jsonlog_test.go new file mode 100644 index 0000000..1f32317 --- /dev/null +++ b/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 +} diff --git a/log/log.go b/log/log.go index 8ec5205..3d31413 100644 --- a/log/log.go +++ b/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 +}