Added methods for returning a structured logger with attached auxiliary info (#15)

* Added methods for returning a structured logger with attached auxiliary info

* updated README

---------

Co-authored-by: Calvin Lobo <[email protected]>

Author: lobocv

Makefile

@@ -1,4 +1,10 @@
 
 
 test:
-	go test ./... -v -count=1 -cover
+	go test ./... -v -count=1 -race -coverprofile coverage_tmp.out && cat coverage_tmp.out | grep -v ping > coverage.out
+
+lint:
+	golangci-lint run
+
+view-coverage: test
+	go tool cover -html=coverage.out

README.md

@@ -24,7 +24,8 @@ The `SimpleError` allows you to easily:
 
 - Apply an error code to any error. Choose from a list of standard codes or [register](https://pkg.go.dev/github.com/lobocv/simplerr#Registry) your own.
 - Automatically translate `simplerr` (including custom codes) error codes to other standardized codes such as `HTTP/gRPC` via middleware.
-- Attach key-value pairs to errors that can be used with structured loggers.
+- Attach key-value pairs to errors
+- Easily log key-value information from errors in structured loggers (slog)
 - Attach and check for custom attributes similar to the `context` package.
 - Automatically capture stack traces at the point the error is raised.
 - Mark errors as [`silent`](https://pkg.go.dev/github.com/lobocv/simplerr#SimpleError.Silence) so they can be skipped by logging middleware.
@@ -188,10 +189,30 @@ there is a lack of control when dealing only with the simple `string`-backed err
 
 ### Logging with Structured Loggers
 
-It is good practice to use structured logging to improve observability. However, the standard library error does
-not allow for attaching and retrieving key-value pairs on errors. With `simplerr` you can retrieve a superset of all attached
-key-value data on errors in the chain using [`ExtractAuxiliary()`](https://pkg.go.dev/github.com/lobocv/simplerr#ExtractAuxiliary)
-or on the individual error with [`GetAuxiliary()`](https://pkg.go.dev/github.com/lobocv/simplerr#SimpleError.GetAuxiliary).
+It is good practice to use structured logging to improve observability. With `simplerr` you can attach key-value pairs
+to the `SimplerError` and generate a pre-populated structured logger right from the error:
+
+```go
+
+serr := simplerr.New("not enough credits").Aux("current_credits", 10, "requested_credits", 5)
+log := serr.GetLogger()
+log.Error(serr.Error())
+```
+
+This outputs a log line with the structured key-value information from the SimpleError.
+
+> {"time":"2025-01-24T13:12:12.924564-05:00","level":"ERROR","msg":"not enough credits","requested_credits":50,"current_credits":10}
+
+You can also attach an existing structured logger to a SimpleError:
+
+```go
+log := slog.Default().With("flavour", "vanilla")
+serr := simplerr.New("we do not sell that flavor").Logger(log)
+```
+
+When calling the `GetLogger()` method, the returned logger is built by combining key-value pairs for all errors in the 
+chain. This means that wrapping multiple errors that each attach key-value information will return a structured logger
+preserving all the key-value pairs.
 
 ### Benign Errors
 

errors.go

@@ -2,6 +2,8 @@ package simplerr
 
 import (
 	"fmt"
+	"log/slog"
+	"slices"
 )
 
 // attribute is a key value pair for attributes on errors
@@ -30,6 +32,8 @@ type SimpleError struct {
 	retriable bool
 	// auxiliary are auxiliary informational fields that can be attached to the error
 	auxiliary map[string]interface{}
+	// logger is a scoped logger that can be attached to the error
+	logger *slog.Logger
 	// attr is a list of custom attributes attached the error
 	attr []attribute
 	// stackTrace is the call stack trace for the error
@@ -183,6 +187,41 @@ func (e *SimpleError) Attr(key, value interface{}) *SimpleError {
 	return e
 }
 
+// Logger attaches a structured logger to the error
+func (e *SimpleError) Logger(l *slog.Logger) *SimpleError {
+	e.logger = l
+	return e
+}
+
+// GetLogger returns a structured logger with auxiliary information preset
+// It uses the first found attached structured logger and otherwise uses the default logger
+func (e *SimpleError) GetLogger() *slog.Logger {
+	l := e.logger
+
+	fields := make([]any, 0, 2*len(e.auxiliary))
+	var errInChain = e
+	for errInChain != nil {
+		if l == nil && errInChain.logger != nil {
+			l = errInChain.logger
+		}
+
+		for k, v := range errInChain.GetAuxiliary() {
+			fields = append(fields, v, k) // append backwards because of the slice reversal
+		}
+
+		errInChain = As(errInChain.Unwrap())
+	}
+	// Reverse the slice so that the aux values at the top of the stack take precedent over the lower ones
+	// For cases where there are conflicting keys
+	slices.Reverse(fields)
+
+	if l == nil {
+		l = slog.Default()
+	}
+
+	return l.With(fields...)
+}
+
 // GetDescription returns the description of the error code on the error.
 func (e *SimpleError) GetDescription() string {
 	return registry.CodeDescription(e.code)

errors_test.go

@@ -1,8 +1,11 @@
 package simplerr
 
 import (
+	"bytes"
+	"encoding/json"
 	"errors"
 	"fmt"
+	"log/slog"
 	"strings"
 	"testing"
 
@@ -519,6 +522,100 @@ func (s *TestSuite) TestErrorFormatting() {
 
 }
 
+func setupTestLogger() *bytes.Buffer {
+	var output bytes.Buffer
+	logger := slog.New(slog.NewJSONHandler(&output, nil))
+	slog.SetDefault(logger)
+	return &output
+}
+
+func (s *TestSuite) TestGetLogger() {
+	serr := New("something")
+	s.Equal(slog.Default(), serr.GetLogger(), "without attaching a logger, return the default logger")
+
+	var output bytes.Buffer
+	logger := slog.New(slog.NewJSONHandler(&output, nil))
+	firstLogger := logger.With("first", 1)
+	_ = serr.Logger(firstLogger)
+	s.Equal(firstLogger, serr.GetLogger(), "return the attached logger")
+
+	secondLogger := logger.With("second", 2)
+	serr2 := Wrapf(serr, "wrapped").Logger(secondLogger)
+	s.Equal(secondLogger, serr2.GetLogger(), "return the first attached logger in the chain")
+
+	serr3 := Wrapf(serr, "wrapped")
+	s.Equal(firstLogger, serr3.GetLogger(), "return the first attached logger in the chain")
+
+}
+
+func (s *TestSuite) TestAttachedLogger() {
+	output := setupTestLogger()
+	logger := slog.Default().With("scoped", "from_attached_logger")
+	original := fmt.Errorf("original")
+	serr1 := Wrapf(original, "wrapper %d", 1).
+		Aux(
+			"aux_first", 1,
+		).Logger(logger.With("scoped_not_used", "this logger is not used because its deeper in the stack"))
+
+	serr2 := Wrapf(serr1, "wrapper %d", 2).
+		Aux("aux_second", 2).Logger(logger)
+
+	l := serr2.GetLogger()
+	l.Info("Write a log")
+
+	got := map[string]any{}
+	err := json.NewDecoder(output).Decode(&got)
+	s.NoError(err)
+
+	s.Contains(got, "scoped")
+	s.Equal(got["scoped"], "from_attached_logger")
+
+	s.NotContains(got, "scoped_not_used")
+
+	s.Contains(got, "aux_first")
+	s.Equal(got["aux_first"], float64(1))
+
+	s.Contains(got, "aux_second")
+	s.Equal(got["aux_second"], float64(2))
+
+}
+
+func (s *TestSuite) TestAuxLogger() {
+	output := setupTestLogger()
+	original := fmt.Errorf("original")
+	serr1 := Wrapf(original, "wrapper %d", 1).
+		Aux(
+			"first_a", 1,
+			"first_b", 2,
+		)
+
+	serr2 := Wrapf(serr1, "wrapper %d", 2).
+		Aux("first_a", 10,
+			"second_a", 0,
+			"second_a", 20, // should overwrite the previous key
+			"second_b", 30,
+		)
+
+	l := serr2.GetLogger()
+	l.Info("Write a log")
+
+	got := map[string]any{}
+	err := json.NewDecoder(output).Decode(&got)
+	s.NoError(err)
+
+	s.Contains(got, "first_a")
+	s.Equal(got["first_a"], float64(10), "first_a should be overwritten with 10 due to name conflict")
+
+	s.Contains(got, "first_b")
+	s.Equal(got["first_b"], float64(2), "first_b should not be overwritten")
+
+	s.Contains(got, "second_a")
+	s.Equal(got["second_a"], float64(20), "second_a should use the latest value due to name conflict")
+
+	s.Contains(got, "second_b")
+	s.Equal(got["second_b"], float64(30))
+}
+
 func (s *TestSuite) TestStackTrace() {
 
 	e := First()