HTTP2 - panic: Header called after Handler finished

[timothysc]

Please answer these questions before submitting your issue. Thanks!

1. What version of Go are you using (go version)?
   1.6.2
2. What operating system and processor architecture are you using (go env)?
   amd64
3. What did you do?
   See API server panics when writing response kubernetes/kubernetes#29001
4. What did you expect to see?
   No issues
5. What did you see instead?

panic: Header called after Handler finished

goroutine 54829830 [running]:
panic(0x20f0220, 0xc821e07010)
        /usr/local/go/src/runtime/panic.go:481 +0x3e6
net/http.(*http2responseWriter).Header(0xc956288948, 0x7fe725a76c88)
        /usr/local/go/src/net/http/h2_bundle.go:4452 +0x78
k8s.io/kubernetes/pkg/httplog.(*respLogger).Header(0xc9702bd260, 0x0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/httplog/log.go:170 +0x3a
k8s.io/kubernetes/pkg/apiserver.(*baseTimeoutWriter).Header(0xc9c39fb9e0, 0x0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:238 +0x39
k8s.io/kubernetes/pkg/apiserver.logStackOnRecover(0x7fe725d5b8a8, 0xc82014ad90, 0x20f0220, 0xc8f69cd900, 0x7fe725b36be8, 0xc8fc256620)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/apiserver.go:213 +0x2d9
k8s.io/kubernetes/pkg/apiserver.InstallRecoverHandler.func1(0x20f0220, 0xc8f69cd900, 0x7fe725b36be8, 0xc8fc256620)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/apiserver.go:195 +0x5e
k8s.io/kubernetes/vendor/github.com/emicklei/go-restful.(*Container).dispatch.func2(0xc82032cea0, 0xc83a235710)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/emicklei/go-restful/container.go:206 +0x6a
panic(0x20f0220, 0xc8f69cd900)
        /usr/local/go/src/runtime/panic.go:443 +0x4e9
net/http.(*http2responseWriter).Header(0xc956288948, 0x2)
        /usr/local/go/src/net/http/h2_bundle.go:4452 +0x78
k8s.io/kubernetes/pkg/httplog.(*respLogger).Header(0xc9702bd260, 0x2decc58)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/httplog/log.go:170 +0x3a
k8s.io/kubernetes/pkg/apiserver.(*baseTimeoutWriter).Header(0xc9c39fb9e0, 0x0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:238 +0x39
k8s.io/kubernetes/pkg/apiserver/metrics.(*fancyResponseWriterDelegator).Header(0xc8fc256630, 0xc8bc4a8e10)
        <autogenerated>:8 +0x53
k8s.io/kubernetes/pkg/apiserver/metrics.InstrumentRouteFunc.func1(0xc8bee93a10, 0xc90d296780)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/metrics/metrics.go:102 +0x35c
k8s.io/kubernetes/vendor/github.com/emicklei/go-restful.(*Container).dispatch(0xc82032cea0, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/emicklei/go-restful/container.go:272 +0xf30
k8s.io/kubernetes/vendor/github.com/emicklei/go-restful.(*Container).(k8s.io/kubernetes/vendor/github.com/emicklei/go-restful.dispatch)-fm(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/emicklei/go-restful/container.go:120 +0x3e
net/http.HandlerFunc.ServeHTTP(0xc820ceb980, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
net/http.(*ServeMux).ServeHTTP(0xc8202c07b0, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1910 +0x17d
k8s.io/kubernetes/pkg/apiserver.WithAuthorizationCheck.func1(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:485 +0xf4
net/http.HandlerFunc.ServeHTTP(0xc820313ac0, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
k8s.io/kubernetes/pkg/apiserver.WithImpersonation.func1(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:420 +0xfe
net/http.HandlerFunc.ServeHTTP(0xc820313b00, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
k8s.io/kubernetes/pkg/auth/handlers.NewRequestAuthenticator.func1(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/auth/handlers/handlers.go:66 +0x2c9
net/http.HandlerFunc.ServeHTTP(0xc8203f5270, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
k8s.io/kubernetes/pkg/api.NewRequestContextFilter.func1(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/api/requestcontext.go:101 +0x157
net/http.HandlerFunc.ServeHTTP(0xc820522660, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
k8s.io/kubernetes/pkg/api.NewRequestContextFilter.func1(0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/api/requestcontext.go:101 +0x157
net/http.HandlerFunc.ServeHTTP(0xc820522680, 0x7fe725b36be8, 0xc8fc256620, 0xc83c513260)
        /usr/local/go/src/net/http/server.go:1618 +0x3a
k8s.io/kubernetes/pkg/apiserver.(*timeoutHandler).ServeHTTP.func1(0xc8216ec9c0, 0x7fe725b36ba8, 0xc8fc256620, 0xc83c513260, 0xc90d296720)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:194 +0x91
created by k8s.io/kubernetes/pkg/apiserver.(*timeoutHandler).ServeHTTP
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:196 +0x15b

[timothysc]

/cc @bradfitz

[bradfitz]

This looks like a bug in Kubernetes. I'll comment on kubernetes/kubernetes#29001 instead.