diff --git a/DESIGN.md b/DESIGN.md index 3c32964..039d3f9 100644 --- a/DESIGN.md +++ b/DESIGN.md @@ -3,8 +3,9 @@ This library aims to simplify error handling in Go through the following key fea * One unique function with argument for standard error and go-errors * Variadic options following the "Functional Options" pattern * An error code, obtained by concatenating identifiers defined at each calls of subfunctions, that allow tracing the root cause -* Comply with error interface (Error() string) +* Comply with error interface (Error() string) - a human-readable message, without the stack trace * JSON formatting message with markers +* Structured logging via `slog.LogValuer` - a consistent structured group (stack included) under both the text and JSON handlers # One unique function The signature of this unique function would be: @@ -97,11 +98,16 @@ func call3() error { In the following situation, the program would return ``` -forbidden (19-12-2): permission denied: missing required role: Role='Reader', User='john.doe', File='test.txt', at=[(func='main.call3', file='main.go', line='40'), (func='main.call2', file='main.go', line='27'), (func='main.call1', file='main.go', line='20')], caused by: open test.txt: permission denied +forbidden (19-12-2): permission denied: missing required role: File='test.txt', Role='Reader', User='john.doe', caused by: open test.txt: permission denied ``` +`Error()` is the human-readable form and does not include the stack trace (properties are sorted by key). The stack is available through the `%+v` verb and through `slog` (see below). + # JSON formatting message | Marker | Description | | ------ | -------------------------- | | `%v` | JSON (without stack) | | `%+v` | Extended JSON (with stack) | + +# Structured logging +`*Error` implements `slog.LogValuer`, so under `slog` the error resolves to a single structured group - the same shape under the text and JSON handlers - rather than the JSON handler logging `Error()` while the text handler logs the `%+v` blob. The stack is included (structured logs are for post-mortem debugging), and a `caused by` that is itself an `*Error` is nested as its own group. diff --git a/README.md b/README.md index c758f57..9e87459 100644 --- a/README.md +++ b/README.md @@ -10,6 +10,7 @@ A Go library for enhanced error handling with stack traces, structured error inf - **Single Entry Point**: `Wrap(error, ...Option)` works with both standard errors and go-errors - **Standard Library Compatible**: Implements standard error interface and works with `errors.Is()`, `errors.As()`, and `errors.Unwrap()` - **JSON Serialization**: Built-in JSON marshaling for logging and debugging +- **Structured Logging**: Implements `slog.LogValuer`, so errors render as a consistent structured group under both the `slog` text and JSON handlers (stack included) ## Installation @@ -203,24 +204,26 @@ Is(e, ErrForbidden) // matches an ancestor (innermost) ## Output Format -The `Error()` method produces output in the following format: +The `Error()` method produces a human-readable message in the following format: ``` -title (id): detail1: detail2: detail3: key1='value1', key2='value2', at=[(func='func1Name', file='file.go', line='21'), (func='func2Name', file='file.go', line='10')], caused by: underlying error +title (id): detail1: detail2: detail3: key1='value1', key2='value2', caused by: underlying error ``` +The stack trace is intentionally **not** part of `Error()` - it is noise for CLIs, `%w` chains and plain logging. Use the `%+v` verb or `slog` (see [Structured Logging](#structured-logging-slog)) to get the full message plus stack. The `(id)` segment is omitted when the error has no identifier. + Details are stored as a slice and joined with `: ` when the error is formatted. Each `WithDetail()` or `WithDetailf()` option appends to this slice. Example with multiple details: ``` -database error (1001): connection timeout: retry limit exceeded: host='localhost', port='5432', at=[(func='connectDB', file='db.go', line='42')], caused by: dial tcp: connection refused +database error (1001): connection timeout: retry limit exceeded: host='localhost', port='5432', caused by: dial tcp: connection refused ``` -Example with wrapped error: +Example with wrapped error (no identifier): ``` -unknown error (0): failed to fetch user from database: at=[(func='getUser', file='user.go', line='25')], caused by: connection refused +unknown error: failed to fetch user from database, caused by: connection refused ``` ## JSON formatting message @@ -241,6 +244,28 @@ Example with extended JSON, with stack (%+v): {"title":"forbidden","identifier":[2,12,19],"details":["permission denied","missing required role"],"properties":{"File":"test.txt","Role":"Reader"},"cause":"open test.txt: permission denied","stack":[{"function":"main.call1","file":"/path/to/main.go","line":25},{"function":"main.call2","file":"/path/to/main.go","line":29},{"function":"main.call3","file":"/path/to/main.go","line":38}]} ``` +## Structured Logging (slog) + +`*Error` implements `slog.LogValuer`, so logging an error resolves to a structured group - identically under the text and JSON handlers. Without it, the JSON handler would log the `Error()` string while the text handler logged the `%+v` JSON blob, giving opposite shapes for the same value. The stack **is** included here, since structured logs are meant for post-mortem debugging. + +```go +logger.Error("request failed", "error", err) +``` + +JSON handler - every field is queryable; `identifier` is the concatenated string and `stack` is an array of `{function, file, line}` objects (with the full file path): + +``` +{"time":"...","level":"ERROR","msg":"request failed","error":{"title":"forbidden","identifier":"12-2","details":["permission denied"],"properties":{"File":"test.txt"},"cause":"open test.txt: permission denied","stack":[{"function":"main.call2","file":"/path/to/main.go","line":29},{"function":"main.call1","file":"/path/to/main.go","line":20}]}} +``` + +Text handler - the same group, with each stack frame rendered as ` :` (short file name) instead of a pointer address: + +``` +time=... level=ERROR msg="request failed" error.title=forbidden error.identifier=12-2 error.details="[permission denied]" error.properties=map[File:test.txt] error.cause="open test.txt: permission denied" error.stack="[main.call2 main.go:29 main.call1 main.go:20]" +``` + +A `caused by` that is itself an `*Error` is nested as its own queryable group rather than flattened to a string. + ## Best Practices 1. **Use `Wrap(err, ...options)`** as the single entry point for both standard errors and go-errors; it captures stack traces and applies options. diff --git a/errors.go b/errors.go index f0d0275..23d114d 100644 --- a/errors.go +++ b/errors.go @@ -6,6 +6,7 @@ import ( "errors" "fmt" "io" + "log/slog" "maps" "path/filepath" "runtime" @@ -29,6 +30,15 @@ type Trace struct { Line int `json:"line,omitempty" yaml:"line,omitempty"` } +// String renders the frame as " :", using just the +// base file name so a stack of *Trace prints readably under fmt's %v/%s +// (and therefore under slog's text handler) instead of as pointer +// addresses. JSON consumers still get the full path and structured object +// via the field tags. +func (t Trace) String() string { + return fmt.Sprintf("%s %s:%d", t.Function, filepath.Base(t.File), t.Line) +} + // Error is an enhanced error implementation that supports structured error information, // error wrapping, stack traces, and additional metadata. // @@ -222,8 +232,11 @@ func (e *Error) Unwrap() error { return nil } -// Error returns a formatted string representation of the error, -// including title, identifier, details, properties, location and cause. +// Error returns a human-readable representation of the error: title, +// identifier, details, properties and cause. The stack trace is +// intentionally NOT included here — Error() (and the %s/%q verbs) is the +// message form consumed by CLIs, %w chains and plain logging, where a +// stack is noise. Use the %+v verb for the full message-plus-stack dump. func (e *Error) Error() string { if e == nil { return "" @@ -231,59 +244,77 @@ func (e *Error) Error() string { b := bytes.NewBuffer(nil) - fmt.Fprintf( - b, - "%s (%s):", - strings.ToLower(e.Title), - e.GetIdentifier(), - ) + if id := e.GetIdentifier(); id != "" { + fmt.Fprintf(b, "%s (%s)", strings.ToLower(e.Title), id) + } else { + fmt.Fprint(b, strings.ToLower(e.Title)) + } if len(e.Details) > 0 { - fmt.Fprintf( - b, - " %s:", + fmt.Fprintf(b, ": %s", strings.Join(e.Details, ": ")) + } + + if len(e.Properties) > 0 { + // order by keys for deterministic output + keys := make([]string, 0, len(e.Properties)) + for k := range e.Properties { + keys = append(keys, k) + } + slices.Sort(keys) - strings.Join(e.Details, ": "), - ) + props := make([]string, 0, len(keys)) + for _, k := range keys { + props = append(props, fmt.Sprintf("%s='%v'", k, e.Properties[k])) + } + fmt.Fprintf(b, ": %s", strings.Join(props, ", ")) } - // order by keys before printing for deterministic output - keys := make([]string, 0, len(e.Properties)) - for k := range e.Properties { - keys = append(keys, k) + if e.Cause != nil { + fmt.Fprintf(b, ", caused by: %v", e.Cause.Error()) } - slices.Sort(keys) - for _, k := range keys { - v := e.Properties[k] - fmt.Fprintf(b, " %s='%v',", k, v) + + return b.String() +} + +// LogValue implements slog.LogValuer so the error logs as one consistent, +// structured group under both the text and JSON handlers. Without it the +// JSON handler renders Error() (a string) while the text handler renders +// %+v (JSON), giving opposite shapes for the same value. +// +// The stack is included — the point of a structured error log is +// post-mortem debugging. JSON consumers get the stack as an array of +// {function,file,line} objects (queryable); the text handler renders +// each frame via Trace.String(). The CLI form (Error()) stays +// stack-free: the two audiences are served differently on purpose. +func (e *Error) LogValue() slog.Value { + if e == nil { + return slog.GroupValue() } - if len(e.stack) > 0 { - stack := make([]string, 0, len(e.stack)) - for i := len(e.stack) - 1; i >= 0; i-- { - trace := e.stack[i] - stack = append( - stack, - fmt.Sprintf( - "(func='%s', file='%s', line='%d')", - trace.Function, - filepath.Base(trace.File), - trace.Line, - ), - ) - } - fmt.Fprintf( - b, - " at=[%s]", - strings.Join(stack, ", "), - ) + attrs := make([]slog.Attr, 0, 6) + attrs = append(attrs, slog.String("title", e.Title)) + + if id := e.GetIdentifier(); id != "" { + attrs = append(attrs, slog.String("identifier", id)) + } + + if len(e.Details) > 0 { + attrs = append(attrs, slog.Any("details", e.Details)) + } + + if len(e.Properties) > 0 { + attrs = append(attrs, slog.Any("properties", e.Properties)) } if e.Cause != nil { - fmt.Fprintf(b, ", caused by: %v", e.Cause.Error()) + attrs = append(attrs, slog.Any("cause", e.Cause.error)) + } + + if len(e.stack) > 0 { + attrs = append(attrs, slog.Any("stack", e.stack)) } - return string(bytes.TrimSuffix(bytes.TrimSuffix(b.Bytes(), []byte(",")), []byte(":"))) + return slog.GroupValue(attrs...) } func from(err error, copyStack bool, options ...Option) *Error { diff --git a/errors_test.go b/errors_test.go index fa5cac9..48e946d 100644 --- a/errors_test.go +++ b/errors_test.go @@ -1,8 +1,10 @@ package errors import ( + "bytes" "errors" "fmt" + "log/slog" "regexp" "strings" "testing" @@ -281,17 +283,45 @@ var _ = Describe("Errors", func() { ) result := e.Error() - // Replace line number and function references - result = regexp.MustCompile(`line='\d+'`).ReplaceAllString(result, "line=''") - result = regexp.MustCompile(`func='[a-z0-9\/\.\-]*'`).ReplaceAllString(result, "func=''") Expect(result).To(ContainSubstring("forbidden (932-128):")) Expect(result).To(ContainSubstring("custom client role is 'Reader':")) Expect(result).To(ContainSubstring("missing write permission on the file:")) Expect(result).To(ContainSubstring("File='test.txt'")) Expect(result).To(ContainSubstring("ClientID='1234567890'")) - Expect(result).To(ContainSubstring("at=[(func='', file='errors_test.go', line=''), (func='', file='errors_test.go', line='')]")) Expect(result).To(ContainSubstring("caused by: permission denied")) }) + + It("renders cleanly without dangling separators before the cause", func() { + withProps := Wrap(New("database error"), + WithIdentifier(1001), + WithDetail("connection timeout"), + WithProperty("host", "localhost"), + CausedBy(errPerm), + ) + Expect(withProps.Error()).To(Equal( + "database error (1001): connection timeout: host='localhost', caused by: permission denied", + )) + Expect(withProps.Error()).NotTo(ContainSubstring(",,")) + + withoutProps := Wrap(New("internal error"), + WithDetail("boom"), + CausedBy(errPerm), + ) + Expect(withoutProps.Error()).To(Equal( + "internal error: boom, caused by: permission denied", + )) + Expect(withoutProps.Error()).NotTo(ContainSubstring(":,")) + + titleOnly := Wrap(New("oops"), CausedBy(errPerm)) + Expect(titleOnly.Error()).To(Equal("oops, caused by: permission denied")) + + noCause := Wrap(New("validation failed"), + WithIdentifier(1), + WithDetail("email is required"), + WithProperty("field", "email"), + ) + Expect(noCause.Error()).To(Equal("validation failed (1): email is required: field='email'")) + }) }) Context("When getting JSON representation of an error", func() { @@ -359,6 +389,82 @@ var _ = Describe("Errors", func() { }) }) + Context("When logging an error via slog.LogValuer", func() { + It("resolves to a structured group rather than a string or JSON blob", func() { + e = Wrap(ErrForbidden, + WithIdentifier(128), + WithDetail("missing write permission"), + WithProperty("File", "test.txt"), + CausedBy(errPerm), + ) + + value, ok := e.(*Error) + Expect(ok).To(BeTrue()) + + logged := value.LogValue() + Expect(logged.Kind()).To(Equal(slog.KindGroup)) + + got := map[string]slog.Value{} + for _, a := range logged.Group() { + got[a.Key] = a.Value + } + + Expect(got["title"].String()).To(Equal("forbidden")) + Expect(got["identifier"].String()).To(Equal("128")) + Expect(got).To(HaveKey("details")) + Expect(got).To(HaveKey("properties")) + Expect(got["cause"].String()).To(Equal("permission denied")) + Expect(got).To(HaveKey("stack")) + }) + + It("renders consistently under the text and JSON handlers", func() { + e = Wrap(ErrForbidden, WithDetail("boom")) + + var jsonBuf, textBuf bytes.Buffer + slog.New(slog.NewJSONHandler(&jsonBuf, nil)).Error("op", "error", e) + slog.New(slog.NewTextHandler(&textBuf, nil)).Error("op", "error", e) + + // Both handlers emit the title as a structured field, so + // neither is a raw JSON blob nor the other handler's shape. + Expect(jsonBuf.String()).To(ContainSubstring(`"error":{"title":"forbidden"`)) + Expect(textBuf.String()).To(ContainSubstring("error.title=forbidden")) + Expect(textBuf.String()).NotTo(ContainSubstring(`{"title"`)) + + // The stack renders structurally in JSON and via Trace.String() + // in text — never as pointer addresses. + Expect(jsonBuf.String()).To(ContainSubstring(`"stack":[{"function"`)) + Expect(textBuf.String()).To(ContainSubstring("errors_test.go:")) + Expect(textBuf.String()).NotTo(ContainSubstring("0x")) + }) + + It("nests an *Error cause as its own group rather than flattening it", func() { + inner := Wrap(ErrForbidden, WithIdentifier(7), WithDetail("inner detail")) + e = Wrap(ErrInternal, WithDetail("outer"), CausedBy(inner)) + + value, ok := e.(*Error) + Expect(ok).To(BeTrue()) + + got := map[string]slog.Value{} + for _, a := range value.LogValue().Group() { + got[a.Key] = a.Value + } + + cause := got["cause"].Resolve() + Expect(cause.Kind()).To(Equal(slog.KindGroup)) + + nested := map[string]slog.Value{} + for _, a := range cause.Group() { + nested[a.Key] = a.Value + } + Expect(nested["title"].String()).To(Equal("forbidden")) + Expect(nested["identifier"].String()).To(Equal("7")) + + var jsonBuf bytes.Buffer + slog.New(slog.NewJSONHandler(&jsonBuf, nil)).Error("op", "error", e) + Expect(jsonBuf.String()).To(ContainSubstring(`"cause":{"title":"forbidden"`)) + }) + }) + Context("When wrapping nil", func() { It("should return unknown error with nil cause", func() { e = Wrap(nil)