Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

log/slog: handle panics in LogValuer.LogValue #59141

Closed
pohly opened this issue Mar 20, 2023 · 7 comments
Closed

log/slog: handle panics in LogValuer.LogValue #59141

pohly opened this issue Mar 20, 2023 · 7 comments
Labels
Proposal Proposal-Accepted
Milestone
Go1.21

Comments

@pohly
Copy link

pohly commented Mar 20, 2023

For the sake of making logging resilient against bugs it would be good to handle panics in Value.Resolve when calling LogValuer.LogValue. Currently this is not handled, causing the entire program to crash.

Found when adding slog support to zapr. One of the existing test cases covers this case by using a nil pointer for a type that doesn't support that:

type marshaler struct {
	msg string
}

func (m *marshaler) String() string {
	return m.msg
}

func (m *marshaler) MarshalLog() interface{} {
	return "msg=" + m.msg
}

func (m *marshaler) LogValue() slog.Value {
	return slog.StringValue("msg=" + m.msg)
}

var _ fmt.Stringer = &marshaler{}
var _ logr.Marshaler = &marshaler{}
var _ slog.LogValuer = &marshaler{}

A better implementation of LogValue of course shouldn't crash, but bugs are bugs... 🐛 🐞

cc @jba
@pohly pohly added the Proposal label Mar 20, 2023
@gopherbot gopherbot added this to the Proposal milestone Mar 20, 2023
@pohly pohly mentioned this issue Mar 20, 2023
Closed
@jba
Copy link
Contributor

jba commented Mar 21, 2023

I think you're right. The situation is analogous to a panic in fmt.Formatter.Format.

@rsc
Copy link
Contributor

rsc commented Mar 29, 2023

This proposal has been added to the active column of the proposals project
and will now be reviewed at the weekly proposal review meetings.
— rsc for the proposal review group

@rsc
Copy link
Contributor

rsc commented Apr 6, 2023

Based on the discussion above, this proposal seems like a likely accept.
— rsc for the proposal review group

@Merovius
Copy link
Contributor

Merovius commented Apr 6, 2023 •
edited

FWIW I don't expect to sway anything but I've been repeatedly frustrated by the fmt packages behavior of transforming bugs into strings - which then end up undebuggable because all the context gets dropped. I don't think a panic in a formatter or a LogValue implementation is substantially different from a panic in any other method. Like, we don't wrap every call to a Write with a defer func() { recover() } () either.

So, personally, I agree that this is analogous to fmt, but in my opinion the behavior of fmt was a mistake that should not get repeated.

@jba
Copy link
Contributor

jba commented Apr 8, 2023

@Merovius, I'll try to include some context in the string.

@rsc
Copy link
Contributor

rsc commented Apr 12, 2023

No change in consensus, so accepted. 🎉
This issue now tracks the work of implementing the proposal.
— rsc for the proposal review group

@rsc rsc changed the title proposal: log/slog: handle panics in LogValuer.LogValue log/slog: handle panics in LogValuer.LogValue Apr 12, 2023
@rsc rsc modified the milestones: Proposal, Backlog Apr 12, 2023
@gopherbot
Copy link

Change https://go.dev/cl/484097 mentions this issue: log/slog: catch panics in LogValue

@dmitshur dmitshur modified the milestones: Backlog, Go1.21 Jun 4, 2023
eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
@jba @eric
log/slog: catch panics in LogValue
2b0d31c 
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 golang#59141.

Change-Id: I62e6ff6968d1aa34873e955c2d606d25418a673b
Reviewed-on: https://go-review.googlesource.com/c/go/+/484097
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Alan Donovan <adonovan@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
@jba @eric
log/slog: catch panics in LogValue
6e00e8f 
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 golang#59141.

Change-Id: I62e6ff6968d1aa34873e955c2d606d25418a673b
Reviewed-on: https://go-review.googlesource.com/c/go/+/484097
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Alan Donovan <adonovan@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Proposal Proposal-Accepted
Projects
None yet
Milestone
Go1.21
Development

No branches or pull requests
6 participants
@pohly @rsc @Merovius @dmitshur @gopherbot @jba