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

logger.Info(zap.Any("",*url.URL)) should not panic if *url.URL is nil #495

Closed
yutongp opened this issue Aug 24, 2017 · 3 comments
Closed

Comments

@yutongp
Copy link

yutongp commented Aug 24, 2017

code:

var a *url.URL
l, _ := zap.NewProduction()
l.Info("msg", zap.Any("url", a))

result:

panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1232c70]

goroutine 25 [running]:
testing.tRunner.func1(0xc4200745b0)
	/usr/local/Cellar/go/1.8.3/libexec/src/testing/testing.go:622 +0x29d
panic(0x13e4ec0, 0x16b1430)
	/usr/local/Cellar/go/1.8.3/libexec/src/runtime/panic.go:489 +0x2cf
net/url.(*URL).String(0x0, 0x1430a80, 0x0)
	/usr/local/Cellar/go/1.8.3/libexec/src/net/url/url.go:726 +0x40
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore.Field.AddTo(0x145b2e5, 0x3, 0x18, 0x0, 0x0, 0x0, 0x1430a80, 0x0, 0x1690c80, 0xc420175e40)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore/field.go:163 +0xd52
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore.addFields(0x1690c80, 0xc420175e40, 0xc420015000, 0x1, 0x1)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore/field.go:199 +0x71
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore.(*jsonEncoder).EncodeEntry(0xc420175d20, 0x0, 0xed1315168, 0xd98249d, 0x16bbae0, 0x0, 0x0, 0x145b2af, 0x3, 0x1, ...)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore/json_encoder.go:339 +0x209
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore.(*ioCore).Write(0xc42001de60, 0x0, 0xed1315168, 0xd98249d, 0x16bbae0, 0x0, 0x0, 0x145b2af, 0x3, 0x1, ...)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore/core.go:86 +0xa9
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore.(*CheckedEntry).Write(0xc42008c2c0, 0xc420015000, 0x1, 0x1)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/zapcore/entry.go:215 +0x116
code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap.(*Logger).Info(0xc4200183c0, 0x145b2af, 0x3, 0xc420015000, 0x1, 0x1)
	/Users/yutongpei/Uber/Code/gocode/src/code.uber.internal/engsec/auth-common.git/vendor/go.uber.org/zap/logger.go:187 +0x7f

the problem is zap found out url has a String() function and directly used it. Unfortunately, net/url doesn't perform nil ptr check in String() function.

I don't think zap user should perform the nil ptr check, it is very normal to log a nil value.
I think ideally the String() implementor should do the nil ptr check, but that is hardly enforced for every struct implemented String()
So maybe zap can do the nil ptr check. The easy way is print "<nil>" if input object is nil. The harder way is call String() first(String() may handle nil case already) and trap the panic if there is one.

@yutongp yutongp changed the title zap.Any("",*url.URL) should not panic if *url.URL is nil logger.Info(zap.Any("",*url.URL)) should not panic if *url.URL is nil Aug 24, 2017
@prashantv
Copy link
Collaborator

It's possible (and allowed) for a String method on a nil type to return a valid value:
https://play.golang.org/p/Z1FSBBxsSe

I don't think there's any easy way to detect this without using reflection or unsafe either.

See https://groups.google.com/forum/#!topic/golang-nuts/wnH302gBa4I/discussion

@prashantv
Copy link
Collaborator

I noticed some interesting behaviour when playing with the fmt package, it catches panics when calling the String method, and if the value is nil, it prints <nil>
https://play.golang.org/p/2NfDjhG4dP

From https://golang.org/pkg/fmt/

If an Error or String method triggers a panic when called by a print routine, the fmt package reformats the error message from the panic, decorating it with an indication that it came through the fmt package. For example, if a String method calls panic("bad"), the resulting formatted message will look like

%!s(PANIC=bad)
The %!s just shows the print verb in use when the failure occurred. If the panic is caused by a nil receiver to an Error or String method, however, the output is the undecorated string, "".

We should consider doing something similar in zap, where we do something like:

defer func() {
  if err := recover(); err != nil {
    // use reflect to check if the value is `nil` and add error saying value is nil
    // else add a log saying we panicked trying to call the method with the recovered error
  }
}()

defer has a slight performance overhead, so we'll want to measure the overhead, and whether this is the behaviour we really want. It is more user-friendly, but might obscure some other real error.

@selslack
Copy link

selslack commented Nov 8, 2017

I think all use cases of Field.Interface field should perform a nil check and act as Skip() if value is nil since this behavior is already in place for Error().

In my opinion, it's performant and intuitive solution.

joa added a commit to joa/zap that referenced this issue Mar 27, 2019
This commit ensures any panic raised while encoding zap.Stringer
is catched and reported as an error of the form kError
for a field k. The reported panic is prefixed with "PANIC=" to
distinguish these errors from other encoding errors.

Closes uber-go#495
Closes uber-go#528
cgxxv pushed a commit to cgxxv/zap that referenced this issue Mar 25, 2022
This commit ensures any panic raised while encoding zap.Stringer
is caught and reported as an error as field kError
for a field k. The reported panic is prefixed with "PANIC=" to
distinguish these errors from other encoding errors.

Closes uber-go#495
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging a pull request may close this issue.

3 participants