Bug 1912563 - p&f: carry 97206: clean up executing request on panic
Summary: p&f: carry 97206: clean up executing request on panic
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: kube-apiserver
Version: 4.5
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: ---
: 4.7.0
Assignee: Abu Kashem
QA Contact: Ke Wang
URL:
Whiteboard:
Depends On: 1912575
Blocks: 1912564
TreeView+ depends on / blocked
 
Reported: 2021-01-04 19:07 UTC by Abu Kashem
Modified: 2021-05-06 09:14 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: No Doc Update
Doc Text:
Clone Of:
: 1912564 1912575 (view as bug list)
Environment:
Last Closed: 2021-02-24 15:49:41 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift kubernetes pull 508 0 None closed Bug 1912563: UPSTREAM: 97323: fix the deadlock in priority and fairness config controller 2021-02-16 11:50:41 UTC
Github openshift kubernetes pull 509 0 None closed Bug 1912563: UPSTREAM: 97206: clean up executing request on panic 2021-02-16 11:50:41 UTC
Red Hat Product Errata RHSA-2020:5633 0 None None None 2021-02-24 15:50:01 UTC

Description Abu Kashem 2021-01-04 19:07:35 UTC
Description of problem:
p&f: clean up executing request on panic

carry upstream PR: https://github.com/kubernetes/kubernetes/pull/97206

Comment 2 Ke Wang 2021-01-08 09:15:48 UTC
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

Comment 3 Abu Kashem 2021-01-11 16:42:53 UTC
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.

Comment 4 Ke Wang 2021-01-12 03:05:21 UTC
akashem, we will write one relevant e2e test later. Move the bug VERIFIED first here.

Comment 7 errata-xmlrpc 2021-02-24 15:49:41 UTC
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

Comment 8 Ke Wang 2021-02-25 08:09:38 UTC
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.


Note You need to log in before you can comment on or make changes to this bug.