Description of problem: We want to seek a solution to increase the timeout settings of (--fallback-timeout-duration=300s) for the openshift-kube-apiserver kube-apiserver-startup-monitor pod; so far it is hardcoded as 300s and could not be changed, we would like to see it configurable. Backgound why we neeed this: One of the customers reported a case#03246567, after the initial anaylasis it turned out that when openshift-kube-apiserver installer-<revision>-<cluster> pods was rolling out the apiserver to newer revision and bringing it up, it was not able to complete in 5 minutes, as a result it was in a loop to rollout and failed, then rollback to earlier revision, until it succeed within 5 mins. Following is an example: efrenmi@seroiuts01742[22:25][caotvdu102/ocp/sriov]$ oc get all -n openshift-kube-apiserver NAME READY STATUS RESTARTS AGE pod/installer-29-caotvdu102 0/1 Completed 0 15d pod/installer-31-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-1-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-2-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-3-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-4-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-5-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-6-caotvdu102 0/1 Completed 0 11d pod/installer-32-caotvdu102 0/1 Completed 0 10d pod/installer-33-caotvdu102 0/1 Completed 0 10d pod/installer-33-retry-1-caotvdu102 0/1 Completed 0 10d pod/installer-33-retry-10-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-11-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-12-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-13-caotvdu102 0/1 Completed 0 8d pod/installer-33-retry-14-caotvdu102 0/1 Completed 0 8d pod/installer-33-retry-15-caotvdu102 0/1 Completed 0 8d pod/installer-33-retry-2-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-3-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-4-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-5-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-6-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-7-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-8-caotvdu102 0/1 Completed 0 9d pod/installer-33-retry-9-caotvdu102 0/1 Completed 0 9d pod/installer-34-caotvdu102 0/1 Completed 0 47m pod/installer-34-retry-1-caotvdu102 0/1 Completed 0 12m pod/kube-apiserver-caotvdu102 0/5 PodInitializing 0 32m pod/revision-pruner-29-caotvdu102 0/1 Completed 0 15d pod/revision-pruner-30-caotvdu102 0/1 Completed 0 11d pod/revision-pruner-31-caotvdu102 0/1 Completed 0 11d pod/revision-pruner-32-caotvdu102 0/1 Completed 0 10d pod/revision-pruner-33-caotvdu102 0/1 Completed 0 10d pod/revision-pruner-34-caotvdu102 0/1 Completed 0 47m And crio logs indicated containers/pods were stopped after 5m before kube-apiserver up/running: ---- creating containers one by one Jun 17 12:54:33 caotvdu102 bash[6018]: time="2022-06-17 12:54:33.087464952Z" level=info msg="Creating container: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver" id=8b2970fb-311f-40ef-9d2a-aac023e7d569 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:55:36 caotvdu102 bash[6018]: time="2022-06-17 12:55:36.353721847Z" level=info msg="Created container 1afed7b56d6efed0c3d078b9d5648462153b3cc90f06443f3481a4b088e2d3ee: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver" id=8b2970fb-311f-40ef-9d2a-aac023e7d569 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:55:37 caotvdu102 bash[6018]: time="2022-06-17 12:55:37.184577410Z" level=info msg="Started container" PID=4170509 containerID=1afed7b56d6efed0c3d078b9d5648462153b3cc90f06443f3481a4b088e2d3ee description=openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver id=b44ea258-2941-413d-b6af-1eaa2722fa88 name=/runtime.v1alpha2.RuntimeService/StartContainer sandboxID=93c8dc638b53fa58d0a09e66c017ac2a12be0aa17137335c102ee003d9c77f22 Jun 17 12:55:39 caotvdu102 bash[6018]: time="2022-06-17 12:55:39.248985172Z" level=info msg="Creating container: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-cert-syncer" id=ff4e4571-66f6-49df-bf43-643b89c7ec97 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:57:52 caotvdu102 bash[6018]: time="2022-06-17 12:57:52.703389962Z" level=info msg="CreateCtr: context was either canceled or the deadline was exceeded: context deadline exceeded" id=ff4e4571-66f6-49df-bf43-643b89c7ec97 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:57:39 caotvdu102 bash[6018]: time="2022-06-17 12:57:39.280607382Z" level=info msg="Creating container: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-cert-regeneration-controller" id=ee9d7ccd-b797-4cb6-b327-fe7a4e59b097 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:58:18 caotvdu102 bash[6018]: time="2022-06-17 12:58:18.547666338Z" level=info msg="Created container d19c60b79d6c2a4f062fcabd841746b913209b96b086bc54d1d822be96c66ab2: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-cert-regeneration-controller" id=ee9d7ccd-b797-4cb6-b327-fe7a4e59b097 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:58:19 caotvdu102 bash[6018]: time="2022-06-17 12:58:19.179936878Z" level=info msg="Started container" PID=73039 containerID=d19c60b79d6c2a4f062fcabd841746b913209b96b086bc54d1d822be96c66ab2 description=openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-cert-regeneration-controller id=00c5cf26-6e9e-4fa9-8033-f2a4ea325479 name=/runtime.v1alpha2.RuntimeService/StartContainer sandboxID=93c8dc638b53fa58d0a09e66c017ac2a12be0aa17137335c102ee003d9c77f22 Jun 17 12:58:20 caotvdu102 bash[6018]: time="2022-06-17 12:58:20.459460099Z" level=info msg="Creating container: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-insecure-readyz" id=d0d32299-fc68-4cbe-8aa8-2aabd98a9dc9 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:58:50 caotvdu102 bash[6018]: time="2022-06-17 12:58:50.094470170Z" level=info msg="Created container 904aac0f733d4dc3be829818c05d4b32e1766be9e63b6b7fed1c9177ba4efe68: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-insecure-readyz" id=d0d32299-fc68-4cbe-8aa8-2aabd98a9dc9 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:58:50 caotvdu102 bash[6018]: time="2022-06-17 12:58:50.698630452Z" level=info msg="Started container" PID=97701 containerID=904aac0f733d4dc3be829818c05d4b32e1766be9e63b6b7fed1c9177ba4efe68 description=openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-insecure-readyz id=0d696699-a730-4b0c-abb3-b17fe1d16de3 name=/runtime.v1alpha2.RuntimeService/StartContainer sandboxID=93c8dc638b53fa58d0a09e66c017ac2a12be0aa17137335c102ee003d9c77f22 Jun 17 12:58:51 caotvdu102 bash[6018]: time="2022-06-17 12:58:51.374660164Z" level=info msg="Creating container: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-check-endpoints" id=45ba83e7-0fbb-468d-b86e-9dc55e0f24a7 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:59:34 caotvdu102 bash[6018]: time="2022-06-17 12:59:34.177933368Z" level=info msg="Created container 2c27b054f876426891f50d1589ac36d42ad46f277e925f447e8e87e22694adfb: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-check-endpoints" id=45ba83e7-0fbb-468d-b86e-9dc55e0f24a7 name=/runtime.v1alpha2.RuntimeService/CreateContainer Jun 17 12:59:34 caotvdu102 bash[6018]: time="2022-06-17 12:59:34.993129639Z" level=info msg="Started container" PID=112274 containerID=2c27b054f876426891f50d1589ac36d42ad46f277e925f447e8e87e22694adfb description=openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-check-endpoints id=5f2416e9-9f25-46ac-bdfb-2ef85450eea9 name=/runtime.v1alpha2.RuntimeService/StartContainer sandboxID=93c8dc638b53fa58d0a09e66c017ac2a12be0aa17137335c102ee003d9c77f22 ---- timeout after 5m (2022-06-17 12:54:33 -> 2022-06-17 12:59:34), containers were stopped: Jun 17 12:59:43 caotvdu102 bash[6018]: time="2022-06-17 12:59:43.666889869Z" level=info msg="Stopped container 904aac0f733d4dc3be829818c05d4b32e1766be9e63b6b7fed1c9177ba4efe68: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-insecure-readyz" id=34ccf65b-7199-4983-b7bd-5542771c956e name=/runtime.v1alpha2.RuntimeService/StopContainer Jun 17 12:59:44 caotvdu102 bash[6018]: time="2022-06-17 12:59:44.293330676Z" level=info msg="Stopped container d19c60b79d6c2a4f062fcabd841746b913209b96b086bc54d1d822be96c66ab2: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-cert-regeneration-controller" id=580e4371-04d6-4c94-bced-43300f7dfe0c name=/runtime.v1alpha2.RuntimeService/StopContainer Jun 17 12:59:47 caotvdu102 bash[6018]: time="2022-06-17 12:59:47.575471633Z" level=info msg="Stopped container 2c27b054f876426891f50d1589ac36d42ad46f277e925f447e8e87e22694adfb: openshift-kube-apiserver/kube-apiserver-caotvdu102/kube-apiserver-check-endpoints" id=62ce7700-ebe2-4c79-83c9-62dd04969436 name=/runtime.v1alpha2.RuntimeService/StopContainer ---- And kube-apiserver logs: (started fromm 0617 12:54:09, timedout at 0617 12:59:08) I0617 12:54:09.605708 1 cmd.go:85] (startupmonitor.Options) { Revision: (int) 31, NodeName: (string) (len=10) "caotvdu102", FallbackTimeout: (time.Duration) 5m0s, ResourceDir: (string) (len=36) "/etc/kubernetes/static-pod-resources", ManifestDir: (string) (len=25) "/etc/kubernetes/manifests", TargetName: (string) (len=14) "kube-apiserver", KubeConfig: (string) (len=96) "/etc/kubernetes/static-pod-resources/configmaps/kube-apiserver-cert-syncer-kubeconfig/kubeconfig", InstallerLockFile: (string) (len=39) "/var/lock/kube-apiserver-installer.lock", LogFile: (string) (len=35) "/var/log/kube-apiserver/startup.log", Check: (*startupmonitorreadiness.KubeAPIReadinessChecker)(0xc000a64740)({ restConfig: (*rest.Config)(<nil>), client: (*http.Client)(<nil>), baseRawURL: (string) (len=22) "https://localhost:6443", kubeClient: (*kubernetes.Clientset)(<nil>), currentNodeName: (string) "" }) } .... I0617 12:59:08.913564 1 monitor.go:102] Watching kube-apiserver of revision 31: waiting for kube-apiserver static pod kube-apiserver-caotvdu102 of revision 31, found 29 (UnexpectedRevision) I0617 12:59:08.913598 1 fallback.go:62] Falling back to a previous revision, the target kube-apiserver hasn't become ready in the allotted time I0617 12:59:08.913980 1 fallback.go:128] About to fallback to the last-known-good revision 29 Version-Release number of selected component (if applicable): OCP 4.9.28 How reproducible: Always Steps to Reproduce: Do nothing, regually run command: oc get pods -n openshift-kube-apiserver, you may see some retry pods created, for example: pod/installer-31-retry-1-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-2-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-3-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-4-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-5-caotvdu102 0/1 Completed 0 11d pod/installer-31-retry-6-caotvdu102 0/1 Completed 0 11d Actual results: We may see the retries pods. Expected results: We should not see too many retries; to increase the timeout settings of (--fallback-timeout-duration=300s) may reduce the total nuumber of retries. Additional info:
> https://github.com/openshift/library-go/blob/master/pkg/operator/staticpod/startupmonitor/assets/startup-monitor-pod.yaml#L17 > --fallback-timeout-duration=300s i don't think it is exclusively used for SNO, and 5m is a reasonable timeout threshold. I see two options: - triage and find the root cause - identify where it is taking longer and then make appropriate fixes - in the short term, if there is an urgency, find a way to increase the timeout to 600s exclusively for SNO. (consult the folks involved with SNO platform and find a way to achieve this)
Hi Abu, Thanks for the info. There was another case#03090018 created sometime back(Nov. 2021) and still has no conclusion yet. In short that case was about on customer's SNO cluster why crio took so long to create/start vDU (customer's 5G application) pods/containers especially when there is a fresh vDU deployment happened, and the case mentioned in this BZ is similar but happened on static pods (for now we see kube-apiserver). I am afraid we won't have a solution so soon considering it's been 8 month since case#03090018 was created, vDU pods/containers still can retry several times and eventually succeed, but kube-apiserver is more critical and the cluster could not afford the long downtime of api server, plus the customer saw this on many clusters recently and each time they spent much effort to get the cluster back, that is the reason we want to have a workaround to increase the timeout before we have solution for case#03090018. About the two options you mentioned, - We will leave the root cause analysis be handled in case#03090018, we saw slow progess now. - This 300s is hardcoded now in the statid pod template https://github.com/openshift/library-go/blob/master/pkg/operator/staticpod/startupmonitor/assets/startup-monitor-pod.yaml#L17, and the startupmonitor pod spec is generated by kue-operserver-operator dynamically based on the template. I doubt if there is a way SNO forks can modify this runtime, or if you can imagine any way, please share and I can try it on my cluster first, thanks! //Borball
> I doubt if there is a way SNO forks can modify this runtime, or if you can imagine any way, please share and I can try it on my cluster first, thanks! we need to add necessary plumbing in static pod logic to determine whether the platform is single node, and then take action (used larger timeout) appropriately. for example, we can templatize "fallback-timeout-duration" in https://github.com/openshift/library-go/blob/master/pkg/operator/staticpod/startupmonitor/assets/startup-monitor-pod.yaml#L17 from > - --fallback-timeout-duration=300s to > - --fallback-timeout-duration={{.FallbackTimeoutDuration}} and then implement plumbing to set the fall back timeout from here on https://github.com/openshift/cluster-kube-apiserver-operator/blob/0378867a15c8f34b8286e1c92243a0a6bbdda383/pkg/operator/targetconfigcontroller/targetconfigcontroller.go#L267-L280 `NewIsSingleNodePlatformFn` determines whether the given platform is single node see https://github.com/openshift/cluster-kube-apiserver-operator/blob/7764681777edfa3126981a0a1d390a6060a840a3/vendor/github.com/openshift/library-go/pkg/operator/staticpod/controller/common/helpers.go#L17 usage of `NewIsSingleNodePlatformFn` can be found here - https://github.com/openshift/cluster-kube-apiserver-operator/blob/7764681777edfa3126981a0a1d390a6060a840a3/pkg/operator/starter.go#L236 I would recommend finding out where it is taking longer for static pod to come up, and fix the underlying issue. if it turns out that the fallback timeout is actually not large enough then we are happy to increase it
Dear reporter, we greatly appreciate the bug you have reported here. Unfortunately, due to migration to a new issue-tracking system (https://issues.redhat.com/), we cannot continue triaging bugs reported in Bugzilla. Since this bug has been stale for multiple days, we, therefore, decided to close this bug. If you think this is a mistake or this bug has a higher priority or severity as set today, please feel free to reopen this bug and tell us why. We are going to move every re-opened bug to https://issues.redhat.com. Thank you for your patience and understanding.