Description of problem: p&f: clean up executing request on panic carry upstream PR: https://github.com/kubernetes/kubernetes/pull/97206
oc adm release info --commits registry.ci.openshift.org/ocp/release:4.7.0-0.nightly-2021-01-07-181010 | grep hyperkube hyperkube https://github.com/openshift/kubernetes 74cd459bbb9c4faa57ece429d35e8a3167e87a7b - Checked the PR 508 and run related unit tests against OCP cluster 4.7.0-0.nightly-2021-01-07-181010, $ git log --date=local --pretty="%h %an %cd - %s" 74cd459 | grep ' #508.*tka' b0247ba05bc OpenShift Merge Robot Thu Jan 7 11:47:36 2021 - Merge pull request #508 from tkashem/carry-97323-master $ cd <$GOPATH/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol> $ ls apf_controller_debug.go apf_filter.go controller_test.go debug filter_test.go formatting.go match_test.go rule.go apf_controller.go BUILD counter fairqueuing format gen_test.go metrics $ go test -v -run TestAPFControllerWithGracefulShutdown go: downloading github.com/pkg/errors v0.9.1 go: downloading github.com/gogo/protobuf v1.3.1 go: downloading k8s.io/klog/v2 v2.4.0 go: downloading github.com/google/gofuzz v1.1.0 go: downloading github.com/golang/protobuf v1.4.3 go: downloading k8s.io/utils v0.0.0-20201110183641-67b214c5f920 go: downloading github.com/googleapis/gnostic v0.4.1 go: downloading github.com/go-logr/logr v0.2.0 go: downloading golang.org/x/net v0.0.0-20201110031124-69a78807bb2b go: downloading gopkg.in/inf.v0 v0.9.1 go: downloading github.com/json-iterator/go v1.1.10 go: downloading google.golang.org/protobuf v1.25.0 go: downloading sigs.k8s.io/yaml v1.2.0 go: downloading golang.org/x/crypto v0.0.0-20201002170205-7f63de1d35b0 go: downloading github.com/modern-go/reflect2 v1.0.1 go: downloading github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd go: downloading github.com/evanphx/json-patch v4.9.0+incompatible go: downloading golang.org/x/text v0.3.4 go: downloading golang.org/x/sys v0.0.0-20201112073958-5cba982894dd go: downloading sigs.k8s.io/structured-merge-diff/v4 v4.0.2 go: downloading github.com/davecgh/go-spew v1.1.1 go: downloading golang.org/x/time v0.0.0-20200630173020-3af7569d3a1e go: downloading github.com/hashicorp/golang-lru v0.5.1 go: downloading github.com/google/go-cmp v0.5.2 go: downloading github.com/prometheus/client_golang v1.7.1 go: downloading github.com/prometheus/client_model v0.2.0 go: downloading gopkg.in/yaml.v2 v2.2.8 go: downloading github.com/spf13/pflag v1.0.5 go: downloading golang.org/x/oauth2 v0.0.0-20200107190931-bf48bf16ab8d go: downloading k8s.io/kube-openapi v0.0.0-20201113171705-d219536bb9fd go: downloading github.com/prometheus/common v0.10.0 go: downloading github.com/blang/semver v3.5.1+incompatible go: downloading github.com/prometheus/procfs v0.2.0 go: downloading github.com/beorn7/perks v1.0.1 go: downloading github.com/cespare/xxhash/v2 v2.1.1 go: downloading github.com/matttproud/golang_protobuf_extensions v1.0.2-0.20181231171920-c182affec369 === RUN TestAPFControllerWithGracefulShutdown I0108 16:49:20.910421 2910975 apf_controller.go:261] Starting API Priority and Fairness config controller I0108 16:49:20.924460 2910975 apf_controller.go:266] Running API Priority and Fairness config worker I0108 16:49:21.010588 2910975 apf_controller.go:270] Shutting down API Priority and Fairness config worker controller_test.go:392: waiting for the controller Run function to shutdown gracefully --- PASS: TestAPFControllerWithGracefulShutdown (0.20s) PASS ok k8s.io/apiserver/pkg/util/flowcontrol 0.302s - Checked the PR 509 and run related unit tests against OCP cluster 4.7.0-0.nightly-2021-01-07-181010, $ git log --date=local --pretty="%h %an %cd - %s" 74cd459 | grep ' #509.*tka' 74cd459bbb9 OpenShift Merge Robot Thu Jan 7 16:20:38 2021 - Merge pull request #509 from tkashem/carry-97206-master $ cd <$GOPATH/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/> $ go test -v -run TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter go: downloading github.com/emicklei/go-restful v2.9.5+incompatible go: downloading github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 go: downloading github.com/google/uuid v1.1.2 === RUN TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter === RUN TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter/priority_level_concurrency_is_set_to_1,_request_handler_panics,_next_request_should_not_be_rejected I0108 16:59:41.474228 2911891 apf_controller.go:261] Starting API Priority and Fairness config controller I0108 16:59:41.474534 2911891 apf_controller.go:266] Running API Priority and Fairness config worker priority-and-fairness_test.go:386: polling retry - error: expected to find metrics with matching labels: map[string]string{"priority_level":"test-pl"} E0108 16:59:41.582628 2911891 runtime.go:76] Observed a panic: request handler panic'd as designed - "/request/panic" goroutine 49 [running]: k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP.func1.1(0xc000150b40) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/timeout.go:106 +0x113 panic(0x1616560, 0xc0003ac3d0) /usr/local/go/src/runtime/panic.go:969 +0x175 k8s.io/apiserver/pkg/server/filters.TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter.func1.3(0x7fb79015c938, 0xc000688168, 0xc0002fa700) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/priority-and-fairness_test.go:403 +0x166 net/http.HandlerFunc.ServeHTTP(0xc00018acf0, 0x7fb79015c938, 0xc000688168, 0xc0002fa700) /usr/local/go/src/net/http/server.go:2042 +0x44 k8s.io/apiserver/pkg/server/filters.WithPriorityAndFairness.func1.4() /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/priority-and-fairness.go:127 +0x3c6 k8s.io/apiserver/pkg/util/flowcontrol.(*configController).Handle.func2() /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol/apf_filter.go:133 +0x1aa k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset.(*request).Finish.func1(0xc0002f8210, 0xc0002e9b6f, 0xc000297800) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset/queueset.go:324 +0x62 k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset.(*request).Finish(0xc0002f8210, 0xc000297800, 0xc0003ac1c0) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset/queueset.go:325 +0x5d k8s.io/apiserver/pkg/util/flowcontrol.(*configController).Handle(0xc0000be420, 0x1a121a0, 0xc00020f6b0, 0xc0002f8160, 0x1a126a0, 0xc00029cb80, 0xc0003ac000, 0xc0003ac010, 0xc000297740) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol/apf_filter.go:123 +0x86a k8s.io/apiserver/pkg/server/filters.WithPriorityAndFairness.func1(0x7fb79015c938, 0xc000688168, 0xc0002fa600) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/priority-and-fairness.go:130 +0x5c3 net/http.HandlerFunc.ServeHTTP(0xc00018b050, 0x7fb79015c938, 0xc000688168, 0xc0002fa600) /usr/local/go/src/net/http/server.go:2042 +0x44 k8s.io/apiserver/pkg/server/filters.newHandlerChain.func1(0x7fb79015c938, 0xc000688168, 0xc0002fa500) /home/kewang/work/gows/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/priority-and-fairness_test.go:509 +0x24a net/http.HandlerFunc.ServeHTTP(0xc00018b110, 0x7fb79015c938, 0xc000688168, 0xc0002fa500) /usr/local/go/src/net/http/server.go:2042 +0x44 ... /usr/local/go/src/net/http/server.go:3415 +0x8d net/http.(*http2serverConn).runHandler(0xc000102f00, 0xc000688160, 0xc0002fa200, 0xc000432500) /usr/local/go/src/net/http/h2_bundle.go:5718 +0x8b created by net/http.(*http2serverConn).processHeaders /usr/local/go/src/net/http/h2_bundle.go:5452 +0x505 priority-and-fairness_test.go:433: waiting for the controller to shutdown I0108 16:59:41.585410 2911891 apf_controller.go:270] Shutting down API Priority and Fairness config worker --- PASS: TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter (0.21s) --- PASS: TestPriorityAndFairnessWithPanicRecoverAndTimeoutFilter/priority_level_concurrency_is_set_to_1,_request_handler_panics,_next_request_should_not_be_rejected (0.21s) PASS ok k8s.io/apiserver/pkg/server/filters 0.231s $ cd <$GOPATH/src/github.com/openshift/kubernetes/staging/src/k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset/> $ go test -v -run TestTotalRequestsExecutingWithPanic === RUN TestTotalRequestsExecutingWithPanic --- PASS: TestTotalRequestsExecutingWithPanic (0.00s) PASS ok k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing/queueset 0.008s
kewang, does not look like there is an e2e test we can write to reproduce this issue. so we need to rely on the unit tests here. looks good to me.
akashem, we will write one relevant e2e test later. Move the bug VERIFIED first here.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Moderate: OpenShift Container Platform 4.7.0 security, bug fix, and enhancement update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2020:5633
Refer to bug https://bugzilla.redhat.com/show_bug.cgi?id=1912564#c7, take a supplemental test on 4.7.0 payload with PR 508 and 509 loaded, $ oc get clusterversion NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.7.0 True False 4h6m Cluster version is 4.7.0 $ ./clusterbuster -P server -b 5 -p 10 -D .01 -M 1 -N 6 -r 4 -d 2 -c 10 -m 1000 -v -s 5 -x ... Created 6 namespace(s) Created 60 secret(s) Created 12 service(s) Created 78 object(s) total No any errors in results. Using oc logs command line to check all kube-apiservers, $ oc logs -n openshift-kube-apiserver <kube-apiserver pod name> | grep -iE 'apf_controller.go|apf_filter.go' | grep 'no route' No any errors in results. Comparing the test results for OCP 4.6.9 of bug 1912564#c7, priority and fairness controller on 4.7 works fine.