diff --git a/internal/entryhuman/entry.go b/internal/entryhuman/entry.go index 9751536..f613195 100644 --- a/internal/entryhuman/entry.go +++ b/internal/entryhuman/entry.go @@ -67,6 +67,10 @@ func formatValue(v interface{}) (string, error) { if v == nil { return "", nil } + switch v.(type) { + case error, fmt.Stringer: + return quote(fmt.Sprintf("%+v", v)), nil + } typ := reflect.TypeOf(v) switch typ.Kind() { case reflect.Struct, reflect.Map: diff --git a/internal/entryhuman/entry_test.go b/internal/entryhuman/entry_test.go index 1473712..8b8fa3b 100644 --- a/internal/entryhuman/entry_test.go +++ b/internal/entryhuman/entry_test.go @@ -2,12 +2,14 @@ package entryhuman_test import ( "bytes" + "context" "database/sql" "flag" "fmt" "io" "math" "os" + "strings" "testing" "time" @@ -284,6 +286,52 @@ func TestEntry(t *testing.T) { }) } +func TestContextErrorFormatting(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + err error + expected string + }{ + { + name: "DeadlineExceeded", + err: context.DeadlineExceeded, + expected: "context deadline exceeded", + }, + { + name: "Canceled", + err: context.Canceled, + expected: "context canceled", + }, + { + name: "WrappedDeadlineExceeded", + err: fmt.Errorf("request failed: %w", context.DeadlineExceeded), + expected: "request failed: context deadline exceeded", + }, + } + + for _, tc := range tests { + tc := tc + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + + var buf bytes.Buffer + entryhuman.Fmt(&buf, io.Discard, slog.SinkEntry{ + Level: slog.LevelError, + Message: "something failed", + Fields: slog.M( + slog.Error(tc.err), + ), + }) + + got := buf.String() + assert.False(t, "error not empty object", strings.Contains(got, "error={}")) + assert.True(t, "error contains expected string", strings.Contains(got, tc.expected)) + }) + } +} + func BenchmarkFmt(b *testing.B) { bench := func(b *testing.B, color bool) { nfs := []int{1, 4, 16} diff --git a/map_test.go b/map_test.go index 8b8ea6c..ec6f1eb 100644 --- a/map_test.go +++ b/map_test.go @@ -2,6 +2,7 @@ package slog_test import ( "bytes" + "context" "encoding/json" "io" "runtime" @@ -62,12 +63,12 @@ func TestMap(t *testing.T) { { "msg": "wrap1", "fun": "cdr.dev/slog/v3_test.TestMap.func2", - "loc": "`+mapTestFile+`:41" + "loc": "`+mapTestFile+`:42" }, { "msg": "wrap2", "fun": "cdr.dev/slog/v3_test.TestMap.func2", - "loc": "`+mapTestFile+`:42" + "loc": "`+mapTestFile+`:43" }, "EOF" ], @@ -220,6 +221,26 @@ func TestMap(t *testing.T) { "val": "{meow:hi bar:23 far:600}" }`) }) + + t.Run("contextDeadlineExceeded", func(t *testing.T) { + t.Parallel() + + test(t, slog.M( + slog.Error(context.DeadlineExceeded), + ), `{ + "error": "context deadline exceeded" + }`) + }) + + t.Run("contextCanceled", func(t *testing.T) { + t.Parallel() + + test(t, slog.M( + slog.Error(context.Canceled), + ), `{ + "error": "context canceled" + }`) + }) } func indentJSON(t *testing.T, j string) string { diff --git a/sloggers/slogjson/slogjson_test.go b/sloggers/slogjson/slogjson_test.go index faf6b95..a586958 100644 --- a/sloggers/slogjson/slogjson_test.go +++ b/sloggers/slogjson/slogjson_test.go @@ -6,6 +6,7 @@ import ( "database/sql" "fmt" "runtime" + "strings" "testing" sdktrace "go.opentelemetry.io/otel/sdk/trace" @@ -34,7 +35,7 @@ func TestMake(t *testing.T) { l.Error(ctx, "line1\n\nline2", slog.F("wowow", "me\nyou")) j := entryjson.Filter(b.String(), "ts") - exp := fmt.Sprintf(`{"level":"ERROR","msg":"line1\n\nline2","caller":"%v:34","func":"cdr.dev/slog/v3/sloggers/slogjson_test.TestMake","logger_names":["named"],"trace":"%v","span":"%v","fields":{"wowow":"me\nyou"}} + exp := fmt.Sprintf(`{"level":"ERROR","msg":"line1\n\nline2","caller":"%v:35","func":"cdr.dev/slog/v3/sloggers/slogjson_test.TestMake","logger_names":["named"],"trace":"%v","span":"%v","fields":{"wowow":"me\nyou"}} `, slogjsonTestFile, span.SpanContext().TraceID().String(), span.SpanContext().SpanID().String()) assert.Equal(t, "entry", exp, j) } @@ -60,7 +61,44 @@ func TestNoDriverValue(t *testing.T) { l.Error(bg, "error!", slog.F("inval", invalidField), slog.F("val", validField), slog.F("int", validInt)) j := entryjson.Filter(b.String(), "ts") - exp := fmt.Sprintf(`{"level":"ERROR","msg":"error!","caller":"%v:60","func":"cdr.dev/slog/v3/sloggers/slogjson_test.TestNoDriverValue","logger_names":["named"],"fields":{"inval":null,"val":"cat","int":42}} + exp := fmt.Sprintf(`{"level":"ERROR","msg":"error!","caller":"%v:61","func":"cdr.dev/slog/v3/sloggers/slogjson_test.TestNoDriverValue","logger_names":["named"],"fields":{"inval":null,"val":"cat","int":42}} `, slogjsonTestFile) assert.Equal(t, "entry", exp, j) } + +func TestContextErrors(t *testing.T) { + t.Parallel() + + t.Run("DeadlineExceeded", func(t *testing.T) { + t.Parallel() + + b := &bytes.Buffer{} + l := slog.Make(slogjson.Sink(b)) + l.Error(bg, "request failed", slog.Error(context.DeadlineExceeded)) + + j := entryjson.Filter(b.String(), "ts") + assert.True(t, "error contains deadline exceeded", strings.Contains(j, `"error":"context deadline exceeded"`)) + }) + + t.Run("Canceled", func(t *testing.T) { + t.Parallel() + + b := &bytes.Buffer{} + l := slog.Make(slogjson.Sink(b)) + l.Error(bg, "request failed", slog.Error(context.Canceled)) + + j := entryjson.Filter(b.String(), "ts") + assert.True(t, "error contains context canceled", strings.Contains(j, `"error":"context canceled"`)) + }) + + t.Run("WrappedDeadlineExceeded", func(t *testing.T) { + t.Parallel() + + b := &bytes.Buffer{} + l := slog.Make(slogjson.Sink(b)) + l.Error(bg, "request failed", slog.Error(fmt.Errorf("dial: %w", context.DeadlineExceeded))) + + j := entryjson.Filter(b.String(), "ts") + assert.True(t, "error contains dial: context deadline exceeded", strings.Contains(j, `"error":"dial: context deadline exceeded"`)) + }) +}