From d5aadf5a52b12170cd9a45e77f590b6902c4df0a Mon Sep 17 00:00:00 2001 From: ichizero <30754019+ichizero@users.noreply.github.com> Date: Sun, 3 Mar 2024 01:06:14 +0900 Subject: [PATCH] feat: Implement errlog --- .golangci.yml | 24 +++------ README.md | 89 ++++++++++++++++++++++++++++++++ errlog.go | 24 +++++++++ errlog_test.go | 36 +++++++++++++ example_test.go | 24 +++++++++ go.sum | 0 handler.go | 92 +++++++++++++++++++++++++++++++++ handler_test.go | 126 +++++++++++++++++++++++++++++++++++++++++++++ stack_trace.go | 70 +++++++++++++++++++++++++ testhelper_test.go | 42 +++++++++++++++ 10 files changed, 510 insertions(+), 17 deletions(-) create mode 100644 errlog.go create mode 100644 errlog_test.go create mode 100644 example_test.go create mode 100644 go.sum create mode 100644 handler.go create mode 100644 handler_test.go create mode 100644 stack_trace.go create mode 100644 testhelper_test.go diff --git a/.golangci.yml b/.golangci.yml index cde85dc..171f33d 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -10,7 +10,14 @@ output: linters: # https://golangci-lint.run/usage/linters/ enable-all: true disable: + - depguard - forbidigo + - exhaustruct + - nlreturn + - paralleltest + - testableexamples + - varnamelen + - wrapcheck - goerr113 # Use errorlint instead. - gofmt # Use gofumpt instead. - testpackage @@ -26,25 +33,8 @@ linters: # https://golangci-lint.run/usage/linters/ - scopelint # deprecated - structcheck # deprecated - varcheck # deprecated -linters-settings: - varnamelen: - max-distance: 15 - ignore-decls: - - E comparable issues: exclude-rules: - path: _test\.go linters: - - containedctx - funlen - - varnamelen - - dupl - - gocognit - - cyclop - - maintidx - - lll - - goconst - - contextcheck - - forcetypeassert - - text: 'shadow: declaration of "(err|ctx)" shadows declaration at' - linters: [ govet ] diff --git a/README.md b/README.md index d4bf497..fbc0a62 100644 --- a/README.md +++ b/README.md @@ -1 +1,90 @@ # errlog + +[![Test](https://github.com/ichizero/errlog/actions/workflows/test.yml/badge.svg)](https://github.com/ichizero/errlog/actions/workflows/test.yml) +[![Go Reference](https://pkg.go.dev/badge/github.com/ichizero/errlog.svg)](https://pkg.go.dev/github.com/ichizero/errlog) +[![Codecov](https://codecov.io/gh/ichizero/errlog/branch/main/graph/badge.svg)](https://codecov.io/gh/ichizero/errlog) +[![Go Report Card](https://goreportcard.com/badge/github.com/ichizero/errlog)](https://goreportcard.com/report/github.com/ichizero/errlog) + +`errlog` is a error logging package based on [log/slog](https://pkg.go.dev/log/slog) standard library. +It provides error logging with stack trace and source location. +It does not require any third-party package. + +## 🚀 Installation + +```bash +go get github.com/ichizero/errlog +``` + +## 🧐 Usage + +### Initialize logger +`errlog.NewHandler` wraps `slog.Handler`, so you can provide `*slog.JSONHandler`, `*slog.TextHandler`, +or any other handler. + +```go +h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true}) +hErr := errlog.NewHandler(h, &errlog.HandlerOptions{OverrideSource: true, SuppressStackTrace: false}) +slog.SetDefault(slog.New(hErr)) +``` + +### Logging error with stack trace + +#### With errlog.Err +`errlog.Err` wraps error with stack trace and returns `slog.Attr` with key `error`. + +```go +err := errors.New("test error") +slog.ErrorContext(ctx, "test", errlog.Err(err)) +``` + +#### With custom error + +`errlog.NewHandler` outputs stack trace with the error that implements `errlog.StackTrace` interface, +so you can provide custom error with stack trace. + +```go +type yourCustomError struct { + err error + stack []uintptr +} + +func (e yourCustomError) Stack() []uintptr { + return e.stack +} +``` + +If so, you can log stack trace without using `errlog.Err`. + +```go +err := newYourCustomError("error") +slog.ErrorContext(ctx, "test", slog.Any("error", err)) +``` + +#### Example usage + +```go +package main + +import ( + "context" + "errors" + "log/slog" + "os" + + "github.com/ichizero/errlog" +) + +func main() { + h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true}) + hErr := errlog.NewHandler(h, &errlog.HandlerOptions{OverrideSource: true, SuppressStackTrace: false}) + slog.SetDefault(slog.New(hErr)) + + ctx := context.Background() + + err := errors.New("test error") + slog.ErrorContext(ctx, "test", errlog.Err(err)) + + err = errlog.WrapError(err) + slog.ErrorContext(ctx, "test", slog.Any("error", err)) +} +``` diff --git a/errlog.go b/errlog.go new file mode 100644 index 0000000..246e517 --- /dev/null +++ b/errlog.go @@ -0,0 +1,24 @@ +package errlog + +import ( + "log/slog" +) + +const ( + ErrorKey = "error" + StackTraceKey = "stack_trace" +) + +// Err returns an attribute that contains the given error. +// If the error does not implement the StackTracer interface, it will be wrapped with the stack trace. +func Err(err error) slog.Attr { + if _, ok := err.(StackTracer); !ok { + err = wrapError(err, 1) + } + return slog.Any(ErrorKey, err) +} + +// WrapError wraps the given error with a stack trace. +func WrapError(err error) error { + return wrapError(err, 1) +} diff --git a/errlog_test.go b/errlog_test.go new file mode 100644 index 0000000..06c302c --- /dev/null +++ b/errlog_test.go @@ -0,0 +1,36 @@ +package errlog_test + +import ( + "bytes" + "encoding/json" + "log/slog" + "testing" + "testing/slogtest" + + "github.com/ichizero/errlog" +) + +func TestRun(t *testing.T) { + t.Parallel() + + var buf bytes.Buffer + + newHandler := func(*testing.T) slog.Handler { + buf.Reset() + + h := slog.NewJSONHandler(&buf, &slog.HandlerOptions{AddSource: true}) + return errlog.NewHandler(h, &errlog.HandlerOptions{OverrideSource: true, SuppressStackTrace: false}) + } + + result := func(t *testing.T) map[string]any { + t.Helper() + + m := map[string]any{} + if err := json.Unmarshal(buf.Bytes(), &m); err != nil { + t.Fatal(err) + } + return m + } + + slogtest.Run(t, newHandler, result) +} diff --git a/example_test.go b/example_test.go new file mode 100644 index 0000000..59921a6 --- /dev/null +++ b/example_test.go @@ -0,0 +1,24 @@ +package errlog_test + +import ( + "context" + "errors" + "log/slog" + "os" + + "github.com/ichizero/errlog" +) + +func Example() { + h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true}) + hErr := errlog.NewHandler(h, &errlog.HandlerOptions{OverrideSource: true, SuppressStackTrace: false}) + slog.SetDefault(slog.New(hErr)) + + ctx := context.Background() + + err := errors.New("test error") + slog.ErrorContext(ctx, "test", errlog.Err(err)) + + err = errlog.WrapError(err) + slog.ErrorContext(ctx, "test", slog.Any("error", err)) +} diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..e69de29 diff --git a/handler.go b/handler.go new file mode 100644 index 0000000..2655a06 --- /dev/null +++ b/handler.go @@ -0,0 +1,92 @@ +package errlog + +import ( + "context" + "log/slog" +) + +// Handler is a slog.Handler that adds error and stack trace information to log records. +type Handler struct { + base slog.Handler + opts HandlerOptions +} + +var _ slog.Handler = (*Handler)(nil) + +// HandlerOptions contains options for the Handler. +type HandlerOptions struct { + // SuppressStackTrace suppresses the stack trace from being added to log records. + SuppressStackTrace bool + // OverrideSource overrides the source location of the log record with the source location of the error. + OverrideSource bool + // StackTraceFormatter is a function that formats the stack trace. + StackTraceFormatter func(stack []uintptr) string +} + +// NewHandler returns a new Handler that wraps the given base slog.handler. +func NewHandler(base slog.Handler, opts *HandlerOptions) *Handler { + if opts == nil { + opts = &HandlerOptions{} + } + + return &Handler{ + base: base, + opts: *opts, + } +} + +// Enabled is a thin wrapper around the base handler's Enabled method. +func (h *Handler) Enabled(ctx context.Context, level slog.Level) bool { + return h.base.Enabled(ctx, level) +} + +// WithAttrs is a thin wrapper around the base handler's WithAttrs method. +func (h *Handler) WithAttrs(attrs []slog.Attr) slog.Handler { + return &Handler{base: h.base.WithAttrs(attrs)} +} + +// WithGroup is a thin wrapper around the base handler's WithGroup method. +func (h *Handler) WithGroup(name string) slog.Handler { + return &Handler{base: h.base.WithGroup(name)} +} + +// Handle adds error and stack trace information to the log record. +func (h *Handler) Handle(ctx context.Context, r slog.Record) error { + r.Attrs(func(a slog.Attr) bool { + const stopIter = false + + if a.Key != ErrorKey { + return true + } + + err, ok := a.Value.Any().(error) + if !ok { + return stopIter + } + + a.Value = slog.StringValue(err.Error()) + + stack := make([]uintptr, 0) + if str, ok := err.(StackTracer); ok { + stack = str.Stack() + } + + if len(stack) == 0 { + return stopIter + } + + if h.opts.OverrideSource { + r.PC = stack[0] + } + + if !h.opts.SuppressStackTrace { + if h.opts.StackTraceFormatter != nil { + r.AddAttrs(slog.String(StackTraceKey, h.opts.StackTraceFormatter(stack))) + return stopIter + } + r.AddAttrs(slog.String(StackTraceKey, formatStack(stack))) + } + return stopIter + }) + return h.base.Handle(ctx, r) +} diff --git a/handler_test.go b/handler_test.go new file mode 100644 index 0000000..dae5398 --- /dev/null +++ b/handler_test.go @@ -0,0 +1,126 @@ +package errlog_test + +import ( + "context" + "errors" + "log/slog" + "strings" + "testing" + + "github.com/ichizero/errlog" +) + +func TestHandler_Handle_OverrideSource(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + overrideSource bool + wantFileSuffix string + }{ + { + name: "should override source with stack trace", + overrideSource: true, + wantFileSuffix: "errlog/testhelper_test.go", + }, + { + name: "should not override source with stack trace", + overrideSource: false, + wantFileSuffix: "errlog/handler_test.go", + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + logger, buf := newLogger(t, + &slog.HandlerOptions{AddSource: true}, + &errlog.HandlerOptions{OverrideSource: tt.overrideSource}) + + errWithStack := newWrappedError(t) + logger.ErrorContext(context.Background(), "test", slog.Any(errlog.ErrorKey, errWithStack)) + + got := unmarshalLog(t, buf) + + source, ok := got[slog.SourceKey] + assertTrue(t, ok) + + sourceMap, ok := source.(map[string]any) + assertTrue(t, ok) + + file, ok := sourceMap["file"] + assertTrue(t, ok) + + fileStr, ok := file.(string) + assertTrue(t, ok) + + if !strings.HasSuffix(fileStr, tt.wantFileSuffix) { + t.Errorf("file is incorrect: wantFileSuffix=%s, got=%s", tt.wantFileSuffix, file) + } + }) + } +} + +func TestHandler_Handle_StackTrace(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + err error + suppressStackTrace bool + wantStackTrace bool + }{ + { + name: "should not output stack trace when err has no stack trace", + err: errors.New("no stack trace"), + suppressStackTrace: false, + wantStackTrace: false, + }, + { + name: "should not output stack trace when err has no stack trace and suppress option is true", + err: errors.New("no stack trace"), + suppressStackTrace: true, + wantStackTrace: false, + }, + { + name: "should output stack trace when err has stack trace", + err: newWrappedError(t), + suppressStackTrace: false, + wantStackTrace: true, + }, + { + name: "should not output stack trace when err has stack trace but suppress option is true", + err: newWrappedError(t), + suppressStackTrace: true, + wantStackTrace: false, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + logger, buf := newLogger(t, + &slog.HandlerOptions{AddSource: true}, + &errlog.HandlerOptions{SuppressStackTrace: tt.suppressStackTrace}) + + logger.ErrorContext(context.Background(), "test", slog.Any(errlog.ErrorKey, tt.err)) + + got := unmarshalLog(t, buf) + + stackTrace, ok := got[errlog.StackTraceKey] + if tt.wantStackTrace != ok { + t.Errorf("stack trace is incorrect: wantStackTrace=%t, got=%s", tt.wantStackTrace, stackTrace) + } + if !tt.wantStackTrace { + return + } + + stackTraceStr, ok := stackTrace.(string) + assertTrue(t, ok) + + if !strings.Contains(stackTraceStr, "TestHandler_Handle_StackTrace") { + t.Errorf("stack trace is incorrect: got=%s", stackTrace) + } + }) + } +} diff --git a/stack_trace.go b/stack_trace.go new file mode 100644 index 0000000..3f161e8 --- /dev/null +++ b/stack_trace.go @@ -0,0 +1,70 @@ +package errlog + +import ( + "runtime" + "strconv" + "strings" +) + +// StackTracer is an interface that represents an error that can provide a stack trace. +type StackTracer interface { + Stack() []uintptr +} + +func formatStack(stack []uintptr) string { + frames := runtime.CallersFrames(stack) + + var sb strings.Builder + + for { + frame, more := frames.Next() + + sb.WriteString(frame.Function) + sb.WriteString("\n\t") + sb.WriteString(frame.File) + sb.WriteString(":") + sb.WriteString(strconv.Itoa(frame.Line)) + sb.WriteString("\n") + + if !more { + break + } + } + + return sb.String() +} + +type withStackTraceError struct { + err error + stack []uintptr +} + +var ( + _ error = (*withStackTraceError)(nil) + _ StackTracer = (*withStackTraceError)(nil) +) + +func wrapError(err error, additionalSkip int) error { + const skipCount = 2 + const depth = 16 + + stack := make([]uintptr, depth) + frameCount := runtime.Callers(skipCount+additionalSkip, stack) + + return &withStackTraceError{ + err: err, + stack: stack[:frameCount], + } +} + +func (e withStackTraceError) Error() string { + return e.err.Error() +} + +func (e withStackTraceError) Unwrap() error { + return e.err +} + +func (e withStackTraceError) Stack() []uintptr { + return e.stack +} diff --git a/testhelper_test.go b/testhelper_test.go new file mode 100644 index 0000000..676f3fa --- /dev/null +++ b/testhelper_test.go @@ -0,0 +1,42 @@ +package errlog_test + +import ( + "bytes" + "encoding/json" + "errors" + "log/slog" + "testing" + + "github.com/ichizero/errlog" +) + +func newWrappedError(t *testing.T) error { + t.Helper() + return errlog.WrapError(errors.New("test error")) +} + +func newLogger(t *testing.T, sOpts *slog.HandlerOptions, eOpts *errlog.HandlerOptions) (*slog.Logger, *bytes.Buffer) { + t.Helper() + var buf bytes.Buffer + + h := slog.NewJSONHandler(&buf, sOpts) + return slog.New(errlog.NewHandler(h, eOpts)), &buf +} + +func unmarshalLog(t *testing.T, buf *bytes.Buffer) map[string]any { + t.Helper() + + m := map[string]any{} + if err := json.Unmarshal(buf.Bytes(), &m); err != nil { + t.Fatal(err) + } + return m +} + +func assertTrue(t *testing.T, value bool) { + t.Helper() + + if !value { + t.Error("Should be true") + } +}