Skip to content

Commit 0aa8998

Browse files
dannykoppingclaude
andcommitted
fix: render error types as strings in human log sink
`formatValue` checked `reflect.Struct` before checking the `error` interface, so struct-typed errors like `context.DeadlineExceeded` were serialized via `json.Marshal` as `{}` instead of their error string. Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
1 parent 348ac12 commit 0aa8998

6 files changed

Lines changed: 117 additions & 5 deletions

File tree

go.mod

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ require (
2828
github.com/mattn/go-runewidth v0.0.15 // indirect
2929
github.com/muesli/reflow v0.3.0 // indirect
3030
github.com/rivo/uniseg v0.4.4 // indirect
31+
github.com/stretchr/testify v1.11.1 // indirect
3132
go.opentelemetry.io/otel v1.16.0 // indirect
3233
go.opentelemetry.io/otel/metric v1.16.0 // indirect
3334
golang.org/x/net v0.12.0 // indirect

go.sum

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,8 @@ github.com/rivo/uniseg v0.1.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJ
3838
github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc=
3939
github.com/rivo/uniseg v0.4.4 h1:8TfxU8dW6PdqD27gjM8MVNuicgxIjxpm4K7x4jp8sis=
4040
github.com/rivo/uniseg v0.4.4/go.mod h1:FN3SvrM+Zdj16jyLfmOkMNblXMcoc8DfTHruCPUcx88=
41-
github.com/stretchr/testify v1.8.3 h1:RP3t2pwF7cMEbC1dqtB6poj3niw/9gnV4Cjg5oW5gtY=
41+
github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U=
42+
github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U=
4243
go.opentelemetry.io/otel v1.16.0 h1:Z7GVAX/UkAXPKsy94IU+i6thsQS4nb7LviLpnaNeW8s=
4344
go.opentelemetry.io/otel v1.16.0/go.mod h1:vl0h9NUa1D5s1nv3A5vZOYWn8av4K8Ml6JDeHrT/bx4=
4445
go.opentelemetry.io/otel/metric v1.16.0 h1:RbrpwVG1Hfv85LgnZ7+txXioPDoh6EdbZHo26Q3hqOo=

internal/entryhuman/entry.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,10 @@ func formatValue(v interface{}) (string, error) {
6767
if v == nil {
6868
return "<nil>", nil
6969
}
70+
switch v.(type) {
71+
case error, fmt.Stringer:
72+
return quote(fmt.Sprintf("%+v", v)), nil
73+
}
7074
typ := reflect.TypeOf(v)
7175
switch typ.Kind() {
7276
case reflect.Struct, reflect.Map:

internal/entryhuman/entry_test.go

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,12 +2,14 @@ package entryhuman_test
22

33
import (
44
"bytes"
5+
"context"
56
"database/sql"
67
"flag"
78
"fmt"
89
"io"
910
"math"
1011
"os"
12+
"strings"
1113
"testing"
1214
"time"
1315

@@ -284,6 +286,51 @@ func TestEntry(t *testing.T) {
284286
})
285287
}
286288

289+
func TestContextErrorFormatting(t *testing.T) {
290+
t.Parallel()
291+
292+
tests := []struct {
293+
name string
294+
err error
295+
expected string
296+
}{
297+
{
298+
name: "DeadlineExceeded",
299+
err: context.DeadlineExceeded,
300+
expected: "context deadline exceeded",
301+
},
302+
{
303+
name: "Canceled",
304+
err: context.Canceled,
305+
expected: "context canceled",
306+
},
307+
{
308+
name: "WrappedDeadlineExceeded",
309+
err: fmt.Errorf("request failed: %w", context.DeadlineExceeded),
310+
expected: "request failed: context deadline exceeded",
311+
},
312+
}
313+
314+
for _, tc := range tests {
315+
t.Run(tc.name, func(t *testing.T) {
316+
t.Parallel()
317+
318+
var buf bytes.Buffer
319+
entryhuman.Fmt(&buf, io.Discard, slog.SinkEntry{
320+
Level: slog.LevelError,
321+
Message: "something failed",
322+
Fields: slog.M(
323+
slog.Error(tc.err),
324+
),
325+
})
326+
327+
got := buf.String()
328+
assert.False(t, "error not empty object", strings.Contains(got, "error={}"))
329+
assert.True(t, "error contains expected string", strings.Contains(got, tc.expected))
330+
})
331+
}
332+
}
333+
287334
func BenchmarkFmt(b *testing.B) {
288335
bench := func(b *testing.B, color bool) {
289336
nfs := []int{1, 4, 16}

map_test.go

Lines changed: 23 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ package slog_test
22

33
import (
44
"bytes"
5+
"context"
56
"encoding/json"
67
"io"
78
"runtime"
@@ -62,12 +63,12 @@ func TestMap(t *testing.T) {
6263
{
6364
"msg": "wrap1",
6465
"fun": "cdr.dev/slog/v3_test.TestMap.func2",
65-
"loc": "`+mapTestFile+`:41"
66+
"loc": "`+mapTestFile+`:42"
6667
},
6768
{
6869
"msg": "wrap2",
6970
"fun": "cdr.dev/slog/v3_test.TestMap.func2",
70-
"loc": "`+mapTestFile+`:42"
71+
"loc": "`+mapTestFile+`:43"
7172
},
7273
"EOF"
7374
],
@@ -220,6 +221,26 @@ func TestMap(t *testing.T) {
220221
"val": "{meow:hi bar:23 far:600}"
221222
}`)
222223
})
224+
225+
t.Run("contextDeadlineExceeded", func(t *testing.T) {
226+
t.Parallel()
227+
228+
test(t, slog.M(
229+
slog.Error(context.DeadlineExceeded),
230+
), `{
231+
"error": "context deadline exceeded"
232+
}`)
233+
})
234+
235+
t.Run("contextCanceled", func(t *testing.T) {
236+
t.Parallel()
237+
238+
test(t, slog.M(
239+
slog.Error(context.Canceled),
240+
), `{
241+
"error": "context canceled"
242+
}`)
243+
})
223244
}
224245

225246
func indentJSON(t *testing.T, j string) string {

sloggers/slogjson/slogjson_test.go

Lines changed: 40 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ import (
66
"database/sql"
77
"fmt"
88
"runtime"
9+
"strings"
910
"testing"
1011

1112
sdktrace "go.opentelemetry.io/otel/sdk/trace"
@@ -34,7 +35,7 @@ func TestMake(t *testing.T) {
3435
l.Error(ctx, "line1\n\nline2", slog.F("wowow", "me\nyou"))
3536

3637
j := entryjson.Filter(b.String(), "ts")
37-
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"}}
38+
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"}}
3839
`, slogjsonTestFile, span.SpanContext().TraceID().String(), span.SpanContext().SpanID().String())
3940
assert.Equal(t, "entry", exp, j)
4041
}
@@ -60,7 +61,44 @@ func TestNoDriverValue(t *testing.T) {
6061
l.Error(bg, "error!", slog.F("inval", invalidField), slog.F("val", validField), slog.F("int", validInt))
6162

6263
j := entryjson.Filter(b.String(), "ts")
63-
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}}
64+
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}}
6465
`, slogjsonTestFile)
6566
assert.Equal(t, "entry", exp, j)
6667
}
68+
69+
func TestContextErrors(t *testing.T) {
70+
t.Parallel()
71+
72+
t.Run("DeadlineExceeded", func(t *testing.T) {
73+
t.Parallel()
74+
75+
b := &bytes.Buffer{}
76+
l := slog.Make(slogjson.Sink(b))
77+
l.Error(bg, "request failed", slog.Error(context.DeadlineExceeded))
78+
79+
j := entryjson.Filter(b.String(), "ts")
80+
assert.True(t, "error contains deadline exceeded", strings.Contains(j, `"error":"context deadline exceeded"`))
81+
})
82+
83+
t.Run("Canceled", func(t *testing.T) {
84+
t.Parallel()
85+
86+
b := &bytes.Buffer{}
87+
l := slog.Make(slogjson.Sink(b))
88+
l.Error(bg, "request failed", slog.Error(context.Canceled))
89+
90+
j := entryjson.Filter(b.String(), "ts")
91+
assert.True(t, "error contains context canceled", strings.Contains(j, `"error":"context canceled"`))
92+
})
93+
94+
t.Run("WrappedDeadlineExceeded", func(t *testing.T) {
95+
t.Parallel()
96+
97+
b := &bytes.Buffer{}
98+
l := slog.Make(slogjson.Sink(b))
99+
l.Error(bg, "request failed", slog.Error(fmt.Errorf("dial: %w", context.DeadlineExceeded)))
100+
101+
j := entryjson.Filter(b.String(), "ts")
102+
assert.True(t, "error contains dial: context deadline exceeded", strings.Contains(j, `"error":"dial: context deadline exceeded"`))
103+
})
104+
}

0 commit comments

Comments
 (0)