CNI panic in server from reflect.Value

[adammw]

Found this in our logs for a misbehaving node:

2020/07/15 20:00:33 http: panic serving 172.16.249.249:48336: reflect: call of reflect.Value.IsNil on zero Value
goroutine 2668766 [running]:
net/http.(*conn).serve.func1(0xc000c3cbe0)
	/usr/local/go/src/net/http/server.go:1767 +0x13b
panic(0x561ade9ac540, 0xc0011da360)
	/usr/local/go/src/runtime/panic.go:679 +0x1b6
encoding/json.(*encodeState).marshal.func1(0xc000c739e8)
	/usr/local/go/src/encoding/json/encode.go:305 +0x9c
panic(0x561ade9ac540, 0xc0011da360)
	/usr/local/go/src/runtime/panic.go:679 +0x1b6
reflect.Value.IsNil(...)
	/usr/local/go/src/reflect/value.go:1073
encoding/json.ptrEncoder.encode(0xc000cfe210, 0xc0004076c0, 0x0, 0x0, 0x0, 0x100)
	/usr/local/go/src/encoding/json/encode.go:806 +0x1a4
encoding/json.mapEncoder.encode(0xc000f42110, 0xc0004076c0, 0x561ade990460, 0xc000fd1af8, 0x95, 0x100)
	/usr/local/go/src/encoding/json/encode.go:706 +0x353
encoding/json.structEncoder.encode(0xc000d7c000, 0x5, 0x8, 0xc000cfe240, 0xc0004076c0, 0x561adeb79e20, 0xc000fd1aa0, 0x99, 0x100)
	/usr/local/go/src/encoding/json/encode.go:664 +0x308
encoding/json.mapEncoder.encode(0xc000cfe270, 0xc0004076c0, 0x561ade9918a0, 0xc0011da130, 0x195, 0x100)
	/usr/local/go/src/encoding/json/encode.go:706 +0x353
encoding/json.structEncoder.encode(0xc001090fc0, 0x3, 0x4, 0xc000cfe2a0, 0xc0004076c0, 0x561adeaa9640, 0xc0011da120, 0x199, 0x561adce80100)
	/usr/local/go/src/encoding/json/encode.go:664 +0x308
encoding/json.ptrEncoder.encode(0xc000cfe2d0, 0xc0004076c0, 0x561ade86e1a0, 0xc0011da120, 0x16, 0x561ade860100)
	/usr/local/go/src/encoding/json/encode.go:810 +0xb3
encoding/json.(*encodeState).reflectValue(0xc0004076c0, 0x561ade86e1a0, 0xc0011da120, 0x16, 0x561adcd30100)
	/usr/local/go/src/encoding/json/encode.go:337 +0x84
encoding/json.(*encodeState).marshal(0xc0004076c0, 0x561ade86e1a0, 0xc0011da120, 0x561adf980100, 0x0, 0x0)
	/usr/local/go/src/encoding/json/encode.go:309 +0x10d
encoding/json.Marshal(0x561ade86e1a0, 0xc0011da120, 0x561adf937441, 0xc000d58a00, 0x0, 0xc0007efab8, 0x561add91534c)
	/usr/local/go/src/encoding/json/encode.go:161 +0x54
github.com/aws/amazon-vpc-cni-k8s/pkg/ipamd.eniV1RequestHandler.func1(0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/go/src/github.com/aws/amazon-vpc-cni-k8s/pkg/ipamd/introspect.go:134 +0x44
net/http.HandlerFunc.ServeHTTP(0xc000d1e390, 0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/usr/local/go/src/net/http/server.go:2007 +0x46
net/http.(*ServeMux).ServeHTTP(0xc000eb6d00, 0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/usr/local/go/src/net/http/server.go:2387 +0x1bf
github.com/aws/amazon-vpc-cni-k8s/pkg/ipamd.LoggingHandler.ServeHTTP(0x561adec9c900, 0xc000eb6d00, 0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/go/src/github.com/aws/amazon-vpc-cni-k8s/pkg/ipamd/introspect.go:51 +0x17c
net/http.(*ServeMux).ServeHTTP(0xc000eb6d40, 0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/usr/local/go/src/net/http/server.go:2387 +0x1bf
net/http.serverHandler.ServeHTTP(0xc00119a620, 0x561adecd4c00, 0xc0005fa460, 0xc000df7200)
	/usr/local/go/src/net/http/server.go:2802 +0xa6
net/http.(*conn).serve(0xc000c3cbe0, 0x561adecda640, 0xc00064f500)
	/usr/local/go/src/net/http/server.go:1890 +0x877
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2928 +0x386

[mogren]

@adammw What version of the CNI is this? We did have an issue with older versions fixed in #915

[adammw]

Can confirm we're running v1.6.2 here, so this should be solved by v1.7 when it's released?

[mogren]

@adammw I think this is an actual bug in the code that only happens when the introspection endpoint is called, so it's not yet fixed in v1.7.1. I will try to reproduce it and add a fix.

[adammw]

That makes sense, we regularly poll the introspection endpoint in our cluster to gate node readiness as well as try and find potential CNI issues, so it's likely that the code path isn't normally hit by other users not using the introspection endpoint as heavily.

[mogren]

Fixed in #1179 and will be included in the next release.