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.

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

funcr: Handle nil Stringer, Marshaler, error #130

Merged
merged 2 commits into from
Jan 31, 2022

Conversation

thockin
Copy link
Contributor

@thockin thockin commented Jan 19, 2022

Produce a useful error rather than panic.

Fixes #125

funcr/funcr.go Outdated
@@ -341,6 +341,17 @@ const (
flagRawStruct = 0x1 // do not print braces on structs
)

func isNil(i interface{}) bool {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this faster than wrapping the MarshalLog and String invocations in a function which recovers from a failure inside the called function?

That's how Dims solved it in klog:
kubernetes/klog@125dec9#diff-d11e021bcd662e6127823cd93eeac7a9aec303039137c2f27974cff399142e84

It has two advantages:

  • if the interface contains a valid pointer to a struct but the called function then crashes for some other reason (nil access for a field in that struct, for example), then the recovery mechanism catches that, too
  • if the function implementation itself handles nil gracefully, then logging keeps using that fallback instead of making up its own

@thockin
Copy link
Contributor Author

thockin commented Jan 20, 2022 via email

@thockin
Copy link
Contributor Author

thockin commented Jan 20, 2022

Retooled - PTAL

@pohly
Copy link
Contributor

pohly commented Jan 21, 2022

It has a distinct disadvantage, too - if the user code panics for ANY REASON, we'll just eat it and continue. Bad.

We could log the panic as an error - that might raise awareness that the code is not as robust as it needs to be.

Hiding the problem where it won't be noticed isn't good, but I think it's still better than aborting the program. Log calls are often not as well tested as the rest of the code. Suppose someone bumps up the log level to debug some problem and then the program aborts somewhere else entirely because of a nil pointer exception - they might not be able to fix the problem and are stuck.

The point about valid implementation is apt. Looking at how printf does it, I guess that is the better answer..

It dumps the panic: https://go.dev/play/p/KC2odl1qSZf

funcr/funcr.go Outdated
if isNil(m) {
ret = "<nil-logr-marshaler>"
} else {
panic(err)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this should return a string explaining the problem, similar to what fmt.Sprint does.

We could also log an error, to raise awareness.

@thockin
Copy link
Contributor Author

thockin commented Jan 21, 2022 via email

@pohly
Copy link
Contributor

pohly commented Jan 21, 2022 via email

@thockin
Copy link
Contributor Author

thockin commented Jan 21, 2022 via email

@thockin
Copy link
Contributor Author

thockin commented Jan 22, 2022

I put up a Twitter poll and it was almost evenly split between "let the panic happen" and "catch panics and print", with "let them happen" taking a single-digit percentage lead.

Thoughts?

@pohly
Copy link
Contributor

pohly commented Jan 24, 2022

I prefer to emulate the behavior of fmt.

Besides being consistent (why should fmt.Printf continue and logger.Info not?) it also makes a bit more sense to me (see argument above about not making the situation worse when a program is already misbehaving).

Produce a maybe-useful error rather than panic when we are in the middle
of logging a value (similar to fmt.Printf).
@thockin
Copy link
Contributor Author

thockin commented Jan 29, 2022

OK, I retooled to be similar to fmt. Added it to benchmark, but nothing to report.

PTAL

@pohly pohly merged commit 28755ae into go-logr:master Jan 31, 2022
pohly added a commit to pohly/zapr that referenced this pull request Feb 15, 2022
The function might panic. The conclusion in
go-logr/logr#130 was that the logger should
record that.

zapr only needs to do that when it calls MarshalLog. Strings and errors are
handled by zap.

For the sake of simplicity no attempt is made to detect the reason for the
panic. As zapr cannot replace the key, it uses the same replacement value as
funcr because that stands out a bit more compared to the value used by zap.
pohly added a commit to pohly/klog that referenced this pull request Feb 15, 2022
The previous fix only covered fmt.Stringer.String in klog, but not klogr.
error.Error and logr.Marshaler.MarshalLog have the same problem. The
replacement string now captures the error, which makes it consistent with
go-logr/logr#130.
pohly added a commit to pohly/zapr that referenced this pull request Feb 16, 2022
The function might panic. The conclusion in
go-logr/logr#130 was that the logger should
record that.

zapr only needs to do that when it calls MarshalLog. Strings and errors are
handled by zap.

For the sake of simplicity no attempt is made to detect the reason for the
panic. In case of a panic, the key is replaced by "<key>Error" and the value
with "PANIC=<panic reason>". This is consistent with how zap handles panics.
thockin pushed a commit to go-logr/zapr that referenced this pull request Feb 16, 2022
The function might panic. The conclusion in
go-logr/logr#130 was that the logger should
record that.

zapr only needs to do that when it calls MarshalLog. Strings and errors are
handled by zap.

For the sake of simplicity no attempt is made to detect the reason for the
panic. In case of a panic, the key is replaced by "<key>Error" and the value
with "PANIC=<panic reason>". This is consistent with how zap handles panics.
pohly added a commit to pohly/klog that referenced this pull request Feb 17, 2022
The previous fix only covered fmt.Stringer.String in klog, but not klogr.
error.Error and logr.Marshaler.MarshalLog have the same problem. The
replacement string now captures the error, which makes it consistent with
go-logr/logr#130.

Two different corner cases may be handled differently:
- panic for a nil object
- panic for a valid object

Only zapr v1.2.3 handles the panic in MarshalLog.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

funcr: handle fmt.Stringer that panics on nil
2 participants