[go] log/slog: catch panics in LogValue
14 views
Skip to first unread message
Jonathan Amsterdam (Gerrit)
Apr 12, 2023, 4:35:22 PM4/12/23
to goph...@pubsubhelper.golang.org, golang-...@googlegroups.com, Alan Donovan, Gopher Robot, golang-co...@googlegroups.com
Jonathan Amsterdam submitted this change.
3 is the latest approved patch-set.
No files were changed between the latest approved patch-set and the submitted one.
Approvals:
Jonathan Amsterdam: Run TryBots
Alan Donovan: Looks good to me, approved
Gopher Robot: TryBots succeeded
log/slog: catch panics in LogValue
If a LogValue call panics, recover and return an error instead.
The error contains some stack information to make it easier to
find the problem. A number of people complained that panics
in fmt.Formatter.Format functions are hard to debug because
there is no context.
This is an example of the error text:
LogValue panicked
called from log/slog.panickingLogValue.LogValue (/usr/local/google/home/jba/repos/go/src/log/slog/value_test.go:221)
called from log/slog.Value.resolve (/usr/local/google/home/jba/repos/go/src/log/slog/value.go:465)
called from log/slog.Value.Resolve (/usr/local/google/home/jba/repos/go/src/log/slog/value.go:446)
called from log/slog.TestLogValue (/usr/local/google/home/jba/repos/go/src/log/slog/value_test.go:192)
called from testing.tRunner (/usr/local/google/home/jba/repos/go/src/testing/testing.go:1595)
(rest of stack elided)
Fixes #59141.
Change-Id: I62e6ff6968d1aa34873e955c2d606d25418a673b
Reviewed-on: https://go-review.googlesource.com/c/go/+/484097
TryBot-Result: Gopher Robot <go...@golang.org>
Reviewed-by: Alan Donovan <adon...@google.com>
Run-TryBot: Jonathan Amsterdam <j...@google.com>
---
M src/log/slog/value.go
M src/log/slog/value_test.go
2 files changed, 52 insertions(+), 1 deletion(-)
diff --git a/src/log/slog/value.go b/src/log/slog/value.go
index fcfc884..d07d9e3 100644
--- a/src/log/slog/value.go
+++ b/src/log/slog/value.go
@@ -7,8 +7,10 @@
import (
"fmt"
"math"
+ "runtime"
"slices"
"strconv"
+ "strings"
"time"
"unsafe"
)
@@ -448,8 +450,14 @@
return v
}
-func (v Value) resolve() Value {
+func (v Value) resolve() (rv Value) {
orig := v
+ defer func() {
+ if r := recover(); r != nil {
+ rv = AnyValue(fmt.Errorf("LogValue panicked\n%s", stack(3, 5)))
+ }
+ }()
+
for i := 0; i < maxLogValues; i++ {
if v.Kind() != KindLogValuer {
return v
@@ -460,6 +468,30 @@
return AnyValue(err)
}
+func stack(skip, nFrames int) string {
+ pcs := make([]uintptr, nFrames+1)
+ n := runtime.Callers(skip+1, pcs)
+ if n == 0 {
+ return "(no stack)"
+ }
+ frames := runtime.CallersFrames(pcs[:n])
+ var b strings.Builder
+ i := 0
+ for {
+ frame, more := frames.Next()
+ fmt.Fprintf(&b, "called from %s (%s:%d)\n", frame.Function, frame.File, frame.Line)
+ if !more {
+ break
+ }
+ i++
+ if i >= nFrames {
+ fmt.Fprintf(&b, "(rest of stack elided)\n")
+ break
+ }
+ }
+ return b.String()
+}
+
// resolveAttrs replaces the values of the given Attrs with their
// resolutions.
func resolveAttrs(as []Attr) {
diff --git a/src/log/slog/value_test.go b/src/log/slog/value_test.go
index d2c427b..e0c60c3 100644
--- a/src/log/slog/value_test.go
+++ b/src/log/slog/value_test.go
@@ -7,6 +7,7 @@
import (
"fmt"
"reflect"
+ "strings"
"testing"
"time"
"unsafe"
@@ -185,6 +186,20 @@
if !attrsEqual(got2, want2) {
t.Errorf("got %v, want %v", got2, want2)
}
+
+ // Verify that panics in Resolve are caught and turn into errors.
+ v = AnyValue(panickingLogValue{})
+ got = v.Resolve().Any()
+ gotErr, ok := got.(error)
+ if !ok {
+ t.Errorf("expected error, got %T", got)
+ }
+ // The error should provide some context information.
+ // We'll just check that this function name appears in it.
+ fmt.Println(got)
+ if got, want := gotErr.Error(), "TestLogValue"; !strings.Contains(got, want) {
+ t.Errorf("got %q, want substring %q", got, want)
+ }
}
func TestZeroTime(t *testing.T) {
@@ -201,6 +216,10 @@
func (r *replace) LogValue() Value { return r.v }
+type panickingLogValue struct{}
+
+func (panickingLogValue) LogValue() Value { panic("bad") }
+
// A Value with "unsafe" strings is significantly faster:
// safe: 1785 ns/op, 0 allocs
// unsafe: 690 ns/op, 0 allocs
To view, visit change 484097. To unsubscribe, or for help writing mail filters, visit settings.
Reply all
Reply to author
Forward
0 new messages