Bug 2047335

Summary: 'oc get project' caused 'Observed a panic: cannot deep copy core.NamespacePhase' when AllRequestBodies is used
Product: OpenShift Container Platform Reporter: Xingxing Xia <xxia>
Component: openshift-apiserverAssignee: Abu Kashem <akashem>
Status: CLOSED ERRATA QA Contact: Rahul Gangwar <rgangwar>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.10CC: akashem, mfojtik, rgangwar, wlewis
Target Milestone: ---Keywords: Regression
Target Release: 4.11.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: No Doc Update
Doc Text:
Story Points: ---
Clone Of:
: 2047927 (view as bug list) Environment:
Last Closed: 2022-08-10 10:44:20 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2047927    

Description Xingxing Xia 2022-01-27 16:14:08 UTC
Description of problem:
'oc get project' caused 'Observed a panic: cannot deep copy core.NamespacePhase' when AllRequestBodies is used

Version-Release number of selected component (if applicable):
4.10.0-0.nightly-2022-01-26-234447

How reproducible:
Always

Steps to Reproduce:
1. oc edit apiserver cluster, change audit policy to AllRequestBodies.
2. Wait for pods to finish rotation
3. $ oc get project
Error from server (InternalError): an error on the server ("This request caused apiserver to panic. Look in the logs for details.") has prevented the request from succeeding (get projects.project.openshift.io)

$ oc get project default
Error from server (InternalError): an error on the server ("This request caused apiserver to panic. Look in the logs for details.") has prevented the request from succeeding (get projects.project.openshift.io default)

Actual results:
3. As above

Expected results:
3. Should succeed

Additional info:
OAS pod logs panic stack in next comment

Comment 1 Xingxing Xia 2022-01-27 16:15:25 UTC
$ oc logs -n openshift-apiserver ONE_OAS_POD
...
2022-01-27T15:02:37.171735296Z E0127 15:02:37.171633       1 runtime.go:76] Observed a panic: cannot deep copy core.NamespacePhase
2022-01-27T15:02:37.171735296Z goroutine 3466 [running]:
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP.func1.1()
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/filters/timeout.go:105 +0xb0
2022-01-27T15:02:37.171735296Z panic({0x3c598a0, 0xc0020d9d10})
2022-01-27T15:02:37.171735296Z 	runtime/panic.go:1038 +0x215
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filters.WithAudit.func1.1·dwrap·1()
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filters/audit.go:86 +0x2a
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filters.WithAudit.func1.1()
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filters/audit.go:95 +0x250
2022-01-27T15:02:37.171735296Z panic({0x3c598a0, 0xc0020d9d10})
2022-01-27T15:02:37.171735296Z 	runtime/panic.go:1038 +0x215
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/runtime.DeepCopyJSONValue({0x3b8d100, 0xc0020d9c50})
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/runtime/converter.go:639 +0x273
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/apis/meta/v1.(*TableRow).DeepCopy(0xc000592840)
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/apis/meta/v1/deepcopy.go:33 +0xe8
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/apis/meta/v1.(*TableRow).DeepCopyInto(...)
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/apis/meta/v1/zz_generated.deepcopy.go:1068
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/apis/meta/v1.(*Table).DeepCopyInto(0xc005435830, 0xc0054359e0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/apis/meta/v1/zz_generated.deepcopy.go:1001 +0x27c
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/apis/meta/v1.(*Table).DeepCopy(...)
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/apis/meta/v1/zz_generated.deepcopy.go:1013
2022-01-27T15:02:37.171735296Z k8s.io/apimachinery/pkg/apis/meta/v1.(*Table).DeepCopyObject(0xc005435830)
2022-01-27T15:02:37.171735296Z 	k8s.io/apimachinery.1/pkg/apis/meta/v1/zz_generated.deepcopy.go:1019 +0x45
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/audit.copyWithoutManagedFields({0x46faf80, 0xc005435830})
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/audit/request.go:291 +0xb2
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/audit.LogResponseObject({0x4728f38, 0xc003981770}, {0x46faf80, 0xc005435830}, {{0xc005374d41, 0x0}, {0xc005374d3c, 0x0}}, {0x47164d8, 0xc0073c2980})
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/audit/request.go:210 +0x2da
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/handlers/responsewriters.WriteObjectNegotiated({0x47164d8, 0xc0073c2980}, {0x4713c88, 0xc001efb520}, {{0xc005374d41, 0x40ff9db}, {0xc005374d3c, 0x40ff9db}}, {0x4716778, 0xc004d5da00}, ...)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/handlers/responsewriters/writers.go:271 +0x3ff
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/handlers.transformResponseObject({0x4728f38, 0xc003981980}, 0xc001efb520, 0x4, _, {_, _}, _, {0x0, {0x0, ...}, ...}, ...)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/handlers/response.go:137 +0x565
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/handlers.getResourceHandler.func1({0x4716778, 0xc004d5da00}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/handlers/get.go:79 +0x7fc
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints.restfulGetResource.func1(0xc0039818c0, 0xc000c1bc00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/installer.go:1221 +0x5b
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/metrics.InstrumentRouteFunc.func1(0xc0039818c0, 0xc000c1bc00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/metrics/metrics.go:509 +0x223
2022-01-27T15:02:37.171735296Z github.com/emicklei/go-restful.(*Container).dispatch(0xc0005b5560, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	github.com/emicklei/go-restful.5+incompatible/container.go:288 +0x9d1
2022-01-27T15:02:37.171735296Z github.com/emicklei/go-restful.(*Container).Dispatch(...)
2022-01-27T15:02:37.171735296Z 	github.com/emicklei/go-restful.5+incompatible/container.go:199
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x4124941, 0x203001}, 0xc0005b5560, 0xc000755f80}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:146 +0x5bb
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*pathHandler).ServeHTTP(0xc003423040, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:254 +0x385
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*PathRecorderMux).ServeHTTP(0xc00534a300, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:234 +0x70
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x411eed5, 0x203001}, 0xc0036577a0, 0xc000768380}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:154 +0x75c
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*pathHandler).ServeHTTP(0xc002172b00, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:254 +0x385
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*PathRecorderMux).ServeHTTP(0xc00534a300, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:234 +0x70
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x411efed, 0x203001}, 0xc00200eb40, 0xc00036d0a0}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:154 +0x75c
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*pathHandler).ServeHTTP(0xc004724980, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:254 +0x385
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*PathRecorderMux).ServeHTTP(0xc00534a300, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:234 +0x70
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x4127dd7, 0x203001}, 0xc0018830e0, 0xc000670c40}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:154 +0x75c
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*pathHandler).ServeHTTP(0xc000890000, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:254 +0x385
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*PathRecorderMux).ServeHTTP(0xc00534a300, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:234 +0x70
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x4127f2c, 0xc00312a4f0}, 0xc0005b4d80, 0xc000349960}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:154 +0x75c
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*pathHandler).ServeHTTP(0xc005d5ed40, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:254 +0x385
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/mux.(*PathRecorderMux).ServeHTTP(0xc00534a300, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/mux/pathrecorder.go:234 +0x70
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server.director.ServeHTTP({{0x4107c93, 0x469a9b8}, 0xc0005b53b0, 0xc000869f80}, {0x4716778, 0xc004d5d880}, 0xc0073b5c00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/handler.go:154 +0x75c
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filters.WithWebhookDuration.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filters/webhook_duration.go:31 +0x24e
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0xc007356ad0, {0x4716778, 0xc004d5d880}, 0x1c903ea)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackCompleted.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:104 +0x1a5
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0xc000597b80, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filters.WithAuthorization.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filters/authorization.go:64 +0x425
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0x64d6108, {0x4716778, 0xc004d5d880}, 0x0)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:80 +0x178
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0x6372760, {0x4716778, 0xc004d5d880}, 0x3)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/server/filters.WithMaxInFlightLimit.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/server/filters/maxinflight.go:187 +0x29d
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0xc007356ef8, {0x4716778, 0xc004d5d880}, 0x1c903ea)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackCompleted.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:104 +0x1a5
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0xc0073c1200, {0x4716778, 0xc004d5d880}, 0xc0073c0fc0)
2022-01-27T15:02:37.171735296Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171735296Z k8s.io/apiserver/pkg/endpoints/filters.WithImpersonation.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171735296Z 	k8s.io/apiserver.1/pkg/endpoints/filters/impersonation.go:50 +0x21c
2022-01-27T15:02:37.171735296Z net/http.HandlerFunc.ServeHTTP(0x64d6108, {2022-01-27T15:02:37.171824805Z 0x4716778, 0xc004d5d880}, 0xa)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:80 +0x178
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0xc0073577b8, {0x4716778, 0xc004d5d880}, 0x1c903ea)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackCompleted.func1({0x4716778, 0xc004d5d880}, 0xc0073b5b00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:104 +0x1a5
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4729de0, {0x4716778, 0xc004d5d880}, 0xc000881b80)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithAudit.func1({0x4716778, 0xc004d5d820}, 0xc0073b5a00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/audit.go:117 +0x713
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x64d6108, {0x4716778, 0xc004d5d820}, 0xa)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1({0x4716778, 0xc004d5d820}, 0xc0073b5a00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:80 +0x178
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0xc003981560, {0x4716778, 0xc004d5d820}, 0x1c903ea)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackCompleted.func1({0x4716778, 0xc004d5d820}, 0xc0073b5a00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:104 +0x1a5
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f38, {0x4716778, 0xc004d5d820}, 0x42b2e88)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.withAuthentication.func1({0x4716778, 0xc004d5d820}, 0xc0073b5a00)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/authentication.go:80 +0x839
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f00, {0x4716778, 0xc004d5d820}, 0x469a9b8)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1({0x4716778, 0xc004d5d820}, 0xc0073b5800)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filterlatency/filterlatency.go:89 +0x46b
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0xc0045b7e00, {0x4716778, 0xc004d5d820}, 0x19f0912)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP.func1()
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/filters/timeout.go:110 +0x70
2022-01-27T15:02:37.171824805Z created by k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/filters/timeout.go:96 +0x1bd
2022-01-27T15:02:37.171824805Z 
2022-01-27T15:02:37.171824805Z goroutine 3447 [running]:
2022-01-27T15:02:37.171824805Z k8s.io/apimachinery/pkg/util/runtime.logPanic({0x3b8f000, 0xc0020d9e00})
2022-01-27T15:02:37.171824805Z 	k8s.io/apimachinery.1/pkg/util/runtime/runtime.go:74 +0x7d
2022-01-27T15:02:37.171824805Z k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0xc00068c3e8, 0x1, 0x29396e6})
2022-01-27T15:02:37.171824805Z 	k8s.io/apimachinery.1/pkg/util/runtime/runtime.go:48 +0x75
2022-01-27T15:02:37.171824805Z panic({0x3b8f000, 0xc0020d9e00})
2022-01-27T15:02:37.171824805Z 	runtime/panic.go:1038 +0x215
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP(0xc0016c75d8, {0x4708a98, 0xc000012e88}, 0xdf8475800)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/filters/timeout.go:116 +0x337
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.withRequestDeadline.func1({0x4708a98, 0xc000012e88}, 0xc0073b5700)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/request_deadline.go:100 +0x494
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0xc0073b5700, {0x4708a98, 0xc000012e88}, 0x100000000000000)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server/filters.withWaitGroup.func1({0x4708a98, 0xc000012e88}, 0xc0073b5700)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/filters/waitgroup.go:77 +0x766
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f38, {0x4708a98, 0xc000012e88}, 0x88)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithAuditAnnotations.func1({0x4708a98, 0xc000012e88}, 0xc0073b5600)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/audit_annotations.go:36 +0x230
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f38, {0x4708a98, 0xc000012e88}, 0x469a9b8)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithWarningRecorder.func1({0x4708a98, 0xc000012e88}, 0xc0073b5500)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/warning.go:35 +0x2bb
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x3fa4aa0, {0x4708a98, 0xc000012e88}, 0xd)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithCacheControl.func1({0x4708a98, 0xc000012e88}, 0x3)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/cachecontrol.go:31 +0x126
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x203001, {0x4708a98, 0xc000012e88}, 0x30)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server/httplog.withLogging.func1({0x4708a98, 0xc000012e88}, 0xc0073b5500)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/httplog/httplog.go:108 +0xaf
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f38, {0x4708a98, 0xc000012e88}, 0x469a9b8)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithRequestInfo.func1({0x4708a98, 0xc000012e88}, 0xc0073b5400)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/requestinfo.go:39 +0x316
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x4728f38, {0x4708a98, 0xc000012e88}, 0xc0050e78f0)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.withRequestReceivedTimestampWithClock.func1({0x4708a98, 0xc000012e88}, 0xc0073b5300)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/request_received_time.go:38 +0x27e
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x1476d22, {0x4708a98, 0xc000012e88}, 0x0)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.WithMuxAndDiscoveryComplete.func1({0x4708a98, 0xc000012e88}, 0xc0073b5300)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/mux_discovery_complete.go:52 +0x2c2
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x3c91dc0, {0x4708a98, 0xc000012e88}, 0x100000000000008)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server/filters.withPanicRecovery.func1({0x4708a98, 0xc000012e88}, 0xc005359e40)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/filters/wrap.go:74 +0xba
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x3eb80c0, {0x4708a98, 0xc000012e88}, 0x8)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/endpoints/filters.withAuditID.func1({0x4708a98, 0xc000012e88}, 0xc00893e100)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/endpoints/filters/with_auditid.go:66 +0x40d
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0x3eb80c0, {0x4708a98, 0xc000012e88}, 0xd)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z github.com/openshift/library-go/pkg/apiserver/apiserverconfig.WithCacheControl.func1({0x4708a98, 0xc000012e88}, 0xc00893e100)
2022-01-27T15:02:37.171824805Z 	github.com/openshift/library-go.0-20211216141749-1816407208cf/pkg/apiserver/apiserverconfig/cachecontrol.go:33 +0x1bd
2022-01-27T15:02:37.171824805Z net/http.HandlerFunc.ServeHTTP(0xc001adbca0, {0x4708a98, 0xc000012e88}, 0x24)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2046 +0x2f
2022-01-27T15:02:37.171824805Z k8s.io/apiserver/pkg/server.(*APIServerHandler).ServeHTTP(0x0, {0x4708a98, 0xc000012e88}, 0x4728ec8)
2022-01-27T15:02:37.171824805Z 	k8s.io/apiserver.1/pkg/server/handler.go:189 +0x2b
2022-01-27T15:02:37.171824805Z net/http.serverHandler.ServeHTTP({0x0}, {0x4708a98, 0xc000012e88}, 0xc00893e100)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:2878 +0x43b
2022-01-27T15:02:37.171824805Z net/http.initALPNRequest.ServeHTTP({{0x4728f38, 0xc00339bcb0}, 0xc003dc9880, {0xc004a321c0}}, {0x4708a98, 0xc000012e88}, 0xc00893e100)
2022-01-27T15:02:37.171824805Z 	net/http/server.go:3479 +0x245
2022-01-27T15:02:37.171824805Z golang.org/x/net/http2.(*serverConn).runHandler(0x4700ef8, 0x64d6108, 0x0, 0x0)
2022-01-27T15:02:37.171824805Z 	golang.org/x/net.0-20211209124913-491a49abca63/http2/server.go:2184 +0x78
2022-01-27T15:02:37.171824805Z created by golang.org/x/net/http2.(*serverConn).processHeaders
2022-01-27T15:02:37.171824805Z 	golang.org/x/net.0-20211209124913-491a49abca63/http2/server.go:1914 +0x590
2022-01-27T15:02:37.171824805Z E0127 15:02:37.171716       1 wrap.go:58] "apiserver panic'd" method="GET" URI="/apis/project.openshift.io/v1/projects/default" audit-ID="fbb1a4ce-23f9-4a5e-89ba-5e7cc1420a48"
...

Comment 2 Abu Kashem 2022-01-27 21:56:02 UTC
xxia,
can you attach the log file with this error?

Comment 3 Abu Kashem 2022-01-27 21:56:56 UTC
also, do you see similar error in kube-apiserver?

Comment 4 Xingxing Xia 2022-01-28 02:06:47 UTC
Created attachment 1857252 [details]
The OAS pod's logs that have the panic when 'oc get project' is run

Attaching the log file.
I ran below OAS resources: oc get project, oc new-project test-proj, oc delete project test-proj, oc get route, oc get build, only 'oc get project' triggered the panic.
I ran KAS resources like oc get pod, oc get ns, no such issue.
I ran OauthAS resources like oc get user, oc get identity, no such issue.

Then I tested WriteRequestBodies, 'oc get project' does not have such issue.

Then I tested latest 4.9 AllRequestBodies, no such issue, so it is a 4.10 regression, adding the Keywords.

Comment 5 Abu Kashem 2022-01-28 19:36:59 UTC
xxia

Thanks for the information, I tracked it down, I think openshift/openshift-apiserver/pull/272 should fix the issue. Please verify when you have the next build

Comment 7 Rahul Gangwar 2022-01-31 06:38:44 UTC
oc get clusterversion
NAME      VERSION                              AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.11.0-0.nightly-2022-01-28-102930   True        False         55m     Cluster version is 4.11.0-0.nightly-2022-01-28-102930

oc get pod -n openshift-kube-apiserver -l apiserver --show-labels
NAME                                           READY   STATUS    RESTARTS   AGE   LABELS
kube-apiserver-rgangwar-31de4-nmw46-master-0   5/5     Running   0          59m   apiserver=true,app=openshift-kube-apiserver,revision=8
kube-apiserver-rgangwar-31de4-nmw46-master-1   5/5     Running   0          57m   apiserver=true,app=openshift-kube-apiserver,revision=8
kube-apiserver-rgangwar-31de4-nmw46-master-2   5/5     Running   0          54m   apiserver=true,app=openshift-kube-apiserver,revision=8

oc edit apiserver cluster, change audit policy to AllRequestBodies and wait for rotation.

 oc get pod -n openshift-kube-apiserver -l apiserver --show-labels
NAME                                           READY   STATUS    RESTARTS   AGE     LABELS
kube-apiserver-rgangwar-31de4-nmw46-master-0   5/5     Running   0          2m52s   apiserver=true,app=openshift-kube-apiserver,revision=9
kube-apiserver-rgangwar-31de4-nmw46-master-1   5/5     Running   0          5m12s   apiserver=true,app=openshift-kube-apiserver,revision=9
kube-apiserver-rgangwar-31de4-nmw46-master-2   5/5     Running   0          29s     apiserver=true,app=openshift-kube-apiserver,revision=9

Getting same issue and panic errors.

oc get project
Error from server (InternalError): an error on the server ("This request caused apiserver to panic. Look in the logs for details.") has prevented the request from succeeding (get projects.project.openshift.io)

Comment 8 Abu Kashem 2022-01-31 13:52:07 UTC
xxia,
can you confirm that `oc get scc` also causes a panic with the current build?

Comment 9 Abu Kashem 2022-01-31 13:54:43 UTC
rgangwar,
- can you check if the PR made its way onto the build?
- and if you still see the issue, I would need the logs with stack trace

Comment 10 Rahul Gangwar 2022-01-31 15:38:19 UTC
Sorry I my bad check with old version. Not getting issue on this build

oc get clusterversion                                                                                                                                
NAME      VERSION                              AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.11.0-0.nightly-2022-01-31-122457   True        False         24m     Cluster version is 4.11.0-0.nightly-2022-01-31-122457

oc get pod -n openshift-kube-apiserver -l apiserver --show-labels
NAME                                           READY   STATUS    RESTARTS   AGE     LABELS
kube-apiserver-rgangwar-31de4-fp286-master-0   5/5     Running   0          8m51s   apiserver=true,app=openshift-kube-apiserver,revision=5
kube-apiserver-rgangwar-31de4-fp286-master-1   5/5     Running   0          11m     apiserver=true,app=openshift-kube-apiserver,revision=5
kube-apiserver-rgangwar-31de4-fp286-master-2   5/5     Running   0          6m32s   apiserver=true,app=openshift-kube-apiserver,revision=5

rahulgangwar@rgangwar-mac ~ % oc edit apiserver/cluster
apiserver.config.openshift.io/cluster edited

spec:
  audit:
    profile: AllRequestBodies

 oc get pod -n openshift-kube-apiserver -l apiserver --show-labels                                                                
NAME                                           READY   STATUS    RESTARTS   AGE     LABELS
kube-apiserver-rgangwar-31de4-fp286-master-0   5/5     Running   0          6m28s   apiserver=true,app=openshift-kube-apiserver,revision=6
kube-apiserver-rgangwar-31de4-fp286-master-1   5/5     Running   0          88s     apiserver=true,app=openshift-kube-apiserver,revision=6
kube-apiserver-rgangwar-31de4-fp286-master-2   5/5     Running   0          3m53s   apiserver=true,app=openshift-kube-apiserver,revision=6

Not see error now.

oc get project default            
NAME      DISPLAY NAME   STATUS
default                  Active

Comment 11 Abu Kashem 2022-02-01 14:02:32 UTC
moving it to assigned, as i found two more sources of panic with SCC and Templates - here is the PR - https://github.com/openshift/openshift-apiserver/pull/275

Comment 14 Rahul Gangwar 2022-02-03 14:34:07 UTC
oc get clusterversion
NAME      VERSION                         AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.11.0-0.ci-2022-02-03-095452   True        False         4m57s   Cluster version is 4.11.0-0.ci-2022-02-03-095452

oc get pod -n openshift-kube-apiserver -l apiserver --show-labels
NAME                                           READY   STATUS    RESTARTS   AGE     LABELS
kube-apiserver-rgangwar-03de5-fqlrd-master-0   5/5     Running   0          10m     apiserver=true,app=openshift-kube-apiserver,revision=9
kube-apiserver-rgangwar-03de5-fqlrd-master-1   5/5     Running   0          7m52s   apiserver=true,app=openshift-kube-apiserver,revision=9
kube-apiserver-rgangwar-03de5-fqlrd-master-2   5/5     Running   0          13m     apiserver=true,app=openshift-kube-apiserver,revision=9

oc edit apiserver cluster, change audit policy to AllRequestBodies and wait for rotation.

oc edit apiserver/cluster
apiserver.config.openshift.io/cluster edited

spec:
  audit:
    profile: AllRequestBodies

oc get pod -n openshift-kube-apiserver -l apiserver --show-labels 
NAME                                           READY   STATUS    RESTARTS   AGE     LABELS
kube-apiserver-rgangwar-03de5-fqlrd-master-0   5/5     Running   0          6m12s   apiserver=true,app=openshift-kube-apiserver,revision=10
kube-apiserver-rgangwar-03de5-fqlrd-master-1   5/5     Running   0          3m11s   apiserver=true,app=openshift-kube-apiserver,revision=10
kube-apiserver-rgangwar-03de5-fqlrd-master-2   5/5     Running   0          19s     apiserver=true,app=openshift-kube-apiserver,revision=10


oc get project default            
NAME      DISPLAY NAME   STATUS
default                  Active

oc get templates -n openshift|head
NAME                                            DESCRIPTION                                                                        PARAMETERS        OBJECTS
3scale-gateway                                  3scale's APIcast is an NGINX based API gateway used to integrate your interna...   17 (8 blank)      3
amq63-basic                                     Application template for JBoss A-MQ brokers. These can be deployed as standal...   11 (4 blank)      6
amq63-persistent                                An example JBoss A-MQ application. For more information about using this temp...   13 (4 blank)      8
amq63-persistent-ssl                            An example JBoss A-MQ application. For more information about using this temp...   18 (6 blank)      12
amq63-ssl                                       An example JBoss A-MQ application. For more information about using this temp...   16 (6 blank)      10
apicurito                                       Design beautiful, functional APIs with zero coding, using a visual designer f...   7 (1 blank)       7
cache-service                                   Red Hat Data Grid is an in-memory, distributed key/value store.                    8 (1 blank)       4
cakephp-mysql-example                           An example CakePHP application with a MySQL database. For more information ab...   21 (4 blank)      8
cakephp-mysql-persistent                        An example CakePHP application with a MySQL database. For more information ab...   22 (4 blank)      9

cat scc.yaml 
kind: SecurityContextConstraints
apiVersion: v1
metadata:
  name: scc-admin
allowPrivilegedContainer: true
runAsUser:
  type: RunAsAny
seLinuxContext:
  type: RunAsAny
fsGroup:
  type: RunAsAny
supplementalGroups:
  type: RunAsAny
users:
- my-admin-user
groups:
- my-admin-group

oc create -f scc.yaml 
W0203 20:01:33.027325   69452 shim_kubectl.go:55] Using non-groupfied API resources is deprecated and will be removed in a future release, update apiVersion to "security.openshift.io/v1" for your resource
securitycontextconstraints.security.openshift.io/scc-admin created

oc get scc scc-admin
NAME        PRIV   CAPS         SELINUX    RUNASUSER   FSGROUP    SUPGROUP   PRIORITY     READONLYROOTFS   VOLUMES
scc-admin   true   <no value>   RunAsAny   RunAsAny    RunAsAny   RunAsAny   <no value>   false            ["awsElasticBlockStore","azureDisk","azureFile","cephFS","cinder","configMap","csi","downwardAPI","emptyDir","ephemeral","fc","flexVolume","flocker","gcePersistentDisk","gitRepo","glusterfs","iscsi","nfs","persistentVolumeClaim","photonPersistentDisk","portworxVolume","projected","quobyte","rbd","scaleIO","secret","storageOS","vsphere"]

Comment 16 Rahul Gangwar 2022-02-07 04:16:26 UTC
Thanks, Sure for future will I keep in mind.

Comment 19 errata-xmlrpc 2022-08-10 10:44:20 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 (Important: OpenShift Container Platform 4.11.0 bug fix and security 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-2022:5069