log/slog: catch panics during formatting

Fixes #61648

Change-Id: I6b7f4948ca89142a358d74624607daf42ea8b304
Reviewed-on: https://go-review.googlesource.com/c/go/+/514135
Reviewed-by: Jonathan Amsterdam <jba@google.com>
Reviewed-by: Ian Lance Taylor <iant@google.com>
Run-TryBot: Andy Pan <panjf2000@gmail.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Jonathan Amsterdam <jba@google.com>

diff --git a/src/log/slog/handler.go b/src/log/slog/handler.go
index a73983cda39418e54bbc38decac9f0f812deb3b6..d18321fc6f1e3c660b9c5a06b5a66f372aa5c51d 100644 (file)
--- a/src/log/slog/handler.go
+++ b/src/log/slog/handler.go
@@ -9,6 +9,7 @@ import (
        "fmt"
        "io"
        "log/slog/internal/buffer"
+       "reflect"
        "slices"
        "strconv"
        "sync"
@@ -512,6 +513,23 @@ func (s *handleState) appendString(str string) {
 }
 
 func (s *handleState) appendValue(v Value) {
+       defer func() {
+               if r := recover(); r != nil {
+                       // If it panics with a nil pointer, the most likely cases are
+                       // an encoding.TextMarshaler or error fails to guard against nil,
+                       // in which case "<nil>" seems to be the feasible choice.
+                       //
+                       // Adapted from the code in fmt/print.go.
+                       if v := reflect.ValueOf(v.any); v.Kind() == reflect.Pointer && v.IsNil() {
+                               s.appendString("<nil>")
+                               return
+                       }
+
+                       // Otherwise just print the original panic message.
+                       s.appendString(fmt.Sprintf("!PANIC: %v", r))
+               }
+       }()
+
        var err error
        if s.h.json {
                err = appendJSONValue(s, v)

diff --git a/src/log/slog/logger_test.go b/src/log/slog/logger_test.go
index 2f5b31939c04c4561442737feb1bc8b5a272ca7a..559b9d66b4567c74b8c299ccddd9c19c9f578edd 100644 (file)
--- a/src/log/slog/logger_test.go
+++ b/src/log/slog/logger_test.go
@@ -12,6 +12,7 @@ import (
        "io"
        "log"
        loginternal "log/internal"
+       "os"
        "path/filepath"
        "regexp"
        "runtime"
@@ -83,6 +84,13 @@ func TestConnections(t *testing.T) {
        Info("msg", "a", 1)
        checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg a=1`)
        logbuf.Reset()
+       Info("msg", "p", nil)
+       checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg p=<nil>`)
+       logbuf.Reset()
+       var r *regexp.Regexp
+       Info("msg", "r", r)
+       checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: INFO msg r=<nil>`)
+       logbuf.Reset()
        Warn("msg", "b", 2)
        checkLogOutput(t, logbuf.String(), `logger_test.go:\d+: WARN msg b=2`)
        logbuf.Reset()
@@ -571,3 +579,62 @@ func wantAllocs(t *testing.T, want int, f func()) {
                t.Errorf("got %d allocs, want %d", got, want)
        }
 }
+
+// panicTextAndJsonMarshaler is a type that panics in MarshalText and MarshalJSON.
+type panicTextAndJsonMarshaler struct {
+       msg any
+}
+
+func (p panicTextAndJsonMarshaler) MarshalText() ([]byte, error) {
+       panic(p.msg)
+}
+
+func (p panicTextAndJsonMarshaler) MarshalJSON() ([]byte, error) {
+       panic(p.msg)
+}
+
+func TestPanics(t *testing.T) {
+       // Revert any changes to the default logger. This is important because other
+       // tests might change the default logger using SetDefault. Also ensure we
+       // restore the default logger at the end of the test.
+       currentLogger := Default()
+       t.Cleanup(func() {
+               SetDefault(currentLogger)
+               log.SetOutput(os.Stderr)
+               log.SetFlags(log.LstdFlags)
+       })
+
+       var logBuf bytes.Buffer
+       log.SetOutput(&logBuf)
+       log.SetFlags(log.Lshortfile &^ log.LstdFlags)
+
+       SetDefault(New(newDefaultHandler(loginternal.DefaultOutput)))
+       for _, pt := range []struct {
+               in  any
+               out string
+       }{
+               {(*panicTextAndJsonMarshaler)(nil), `logger_test.go:\d+: INFO msg p=<nil>`},
+               {panicTextAndJsonMarshaler{io.ErrUnexpectedEOF}, `logger_test.go:\d+: INFO msg p="!PANIC: unexpected EOF"`},
+               {panicTextAndJsonMarshaler{"panicking"}, `logger_test.go:\d+: INFO msg p="!PANIC: panicking"`},
+               {panicTextAndJsonMarshaler{42}, `logger_test.go:\d+: INFO msg p="!PANIC: 42"`},
+       } {
+               Info("msg", "p", pt.in)
+               checkLogOutput(t, logBuf.String(), pt.out)
+               logBuf.Reset()
+       }
+
+       SetDefault(New(NewJSONHandler(&logBuf, nil)))
+       for _, pt := range []struct {
+               in  any
+               out string
+       }{
+               {(*panicTextAndJsonMarshaler)(nil), `{"time":".*?","level":"INFO","msg":"msg","p":null}`},
+               {panicTextAndJsonMarshaler{io.ErrUnexpectedEOF}, `{"time":".*?","level":"INFO","msg":"msg","p":"!PANIC: unexpected EOF"}`},
+               {panicTextAndJsonMarshaler{"panicking"}, `{"time":".*?","level":"INFO","msg":"msg","p":"!PANIC: panicking"}`},
+               {panicTextAndJsonMarshaler{42}, `{"time":".*?","level":"INFO","msg":"msg","p":"!PANIC: 42"}`},
+       } {
+               Info("msg", "p", pt.in)
+               checkLogOutput(t, logBuf.String(), pt.out)
+               logBuf.Reset()
+       }
+}