Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1860190

Summary: [BM IPI] kube-controller-manager failing after upgrade from 4.4.13 to 4.5.3
Product: OpenShift Container Platform Reporter: Lars Kellogg-Stedman <lars>
Component: kube-controller-managerAssignee: Tomáš Nožička <tnozicka>
Status: CLOSED DUPLICATE QA Contact: zhou ying <yinzhou>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 4.5CC: aos-bugs, dbewley, ipilcher, jmalde, mfojtik, tnozicka
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-07-27 15:29:02 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:
Attachments:
Description Flags
logs from kube-controller-manager-os-mgr-0 pod
none
logs from kube-controller-manager-os-mgr-1 pod
none
logs from kube-controller-manager-os-mgr-2 pod none

Description Lars Kellogg-Stedman 2020-07-23 23:17:12 UTC
Description of problem:

After an upgrade of a stock 4.4.13 baremetal install to 4.5.3, the kube-controller-manager pods are failing:

$ oc -n openshift-kube-controller-manager get pods
NAME                               READY   STATUS             RESTARTS   AGE
kube-controller-manager-os-mgr-0   3/4     CrashLoopBackOff   157        20h
kube-controller-manager-os-mgr-1   3/4     CrashLoopBackOff   155        20h
kube-controller-manager-os-mgr-2   4/4     Running            158        20h

We see errors in the logs that look like this:

E0723 19:36:39.002607       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: Get https://localhost:6443/api/v1/namespaces/kube-system/configmaps/kube-controller-manager?timeout=10s: dial tcp [::1]:6443: connect: connection refused
E0723 19:36:44.255133       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: Get https://localhost:6443/api/v1/namespaces/kube-system/configmaps/kube-controller-manager?timeout=10s: dial tcp [::1]:6443: connect: connection refused
E0723 19:36:50.423418       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: Get https://localhost:6443/api/v1/namespaces/kube-system/configmaps/kube-controller-manager?timeout=10s: dial tcp [::1]:6443: connect: connection refused
E0723 19:36:56.165523       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: Get https://localhost:6443/api/v1/namespaces/kube-system/configmaps/kube-controller-manager?timeout=10s: dial tcp [::1]:6443: connect: connection refused
E0723 19:37:00.270524       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: Get https://localhost:6443/api/v1/namespaces/kube-system/configmaps/kube-controller-manager?timeout=10s: dial tcp [::1]:6443: connect: connection refused
E0723 19:37:04.040597       1 webhook.go:111] Failed to make webhook authenticator request: Post https://localhost:6443/apis/authentication.k8s.io/v1/tokenreviews: dial tcp [::1]:6443: connect: connection refused
E0723 19:37:04.040659       1 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Post https://localhost:6443/apis/authentication.k8s.io/v1/tokenreviews: dial tcp [::1]:6443: connect: connection refused]
E0723 19:37:09.190980       1 leaderelection.go:320] error retrieving resource lock kube-system/kube-controller-manager: configmaps "kube-controller-manager" is forbidden: User "system:kube-controller-manager" cannot get resource "configmaps" in API group "" in the namespace "kube-system"
E0723 19:37:09.196186       1 webhook.go:111] Failed to make webhook authenticator request: tokenreviews.authentication.k8s.io is forbidden: User "system:kube-controller-manager" cannot create resource "tokenreviews" in API group "authentication.k8s.io" at the cluster scope
E0723 19:37:09.196243       1 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, tokenreviews.authentication.k8s.io is forbidden: User "system:kube-controller-manager" cannot create resource "tokenreviews" in API group "authentication.k8s.io" at the cluster scope]

And other errors that look like this:

I0723 23:01:27.893959       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/grafana: Operation cannot be fulfilled on deployments.apps "grafana": the object has been modified; please apply your changes to the latest version and try again
I0723 23:01:27.906086       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/grafana: Operation cannot be fulfilled on deployments.apps "grafana": the object has been modified; please apply your changes to the latest version and try again
I0723 23:05:56.786329       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/openshift-state-metrics: Operation cannot be fulfilled on deployments.apps "openshift-state-metrics": the object has been modified; please apply your changes to the latest version and try again
I0723 23:05:59.384547       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/prometheus-operator: Operation cannot be fulfilled on deployments.apps "prometheus-operator": the object has been modified; please apply your changes to the latest version and try again
I0723 23:05:59.588577       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/kube-state-metrics: Operation cannot be fulfilled on deployments.apps "kube-state-metrics": the object has been modified; please apply your changes to the latest version and try again
I0723 23:06:11.802232       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/telemeter-client: Operation cannot be fulfilled on deployments.apps "telemeter-client": the object has been modified; please apply your changes to the latest version and try again
I0723 23:06:15.414085       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/thanos-querier: Operation cannot be fulfilled on deployments.apps "thanos-querier": the object has been modified; please apply your changes to the latest version and try again
I0723 23:06:15.428269       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/thanos-querier: Operation cannot be fulfilled on deployments.apps "thanos-querier": the object has been modified; please apply your changes to the latest version and try again
I0723 23:06:17.388311       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/prometheus-adapter: Operation cannot be fulfilled on deployments.apps "prometheus-adapter": the object has been modified; please apply your changes to the latest version and try again
I0723 23:06:21.206663       1 deployment_controller.go:485] Error syncing deployment openshift-monitoring/grafana: Operation cannot be fulfilled on deployments.apps "grafana": the object has been modified; please apply your changes to the latest version and try again

I'll attach the complete logs to this bz.

After upgrading to 4.5.3, we made the following configuration changes:

- configure a default ingress certificate
- add an openid connect oauth provider
- install and configure cnv 2.3
- configure a bridge network
- install the keepalived-operator from https://github.com/redhat-cop/keepalived-operator

Comment 1 Lars Kellogg-Stedman 2020-07-23 23:18:18 UTC
Created attachment 1702278 [details]
logs from kube-controller-manager-os-mgr-0 pod

Comment 2 Lars Kellogg-Stedman 2020-07-23 23:18:38 UTC
Created attachment 1702279 [details]
logs from kube-controller-manager-os-mgr-1 pod

Comment 3 Lars Kellogg-Stedman 2020-07-23 23:18:59 UTC
Created attachment 1702280 [details]
logs from kube-controller-manager-os-mgr-2 pod

Comment 4 Lars Kellogg-Stedman 2020-07-24 19:36:11 UTC
I am closing this as a dupe of https://bugzilla.redhat.com/show_bug.cgi?id=1842002.

*** This bug has been marked as a duplicate of bug 1842002 ***

Comment 5 Lars Kellogg-Stedman 2020-07-27 15:20:55 UTC
Tomáš suggested re-opening this bz because he thinks it's a different issue from #1842002.  Here's a link to the must-gather information from a fresh 4.5.3 install that is exhibiting these sypmtoms:

https://drive.google.com/file/d/1zxcRTbWlByQDwt_SUAEM23IYQLj9hCfT/view?usp=sharing

Comment 6 Tomáš Nožička 2020-07-27 15:29:02 UTC
this is the haproxy stealing KCM port

  - containerID: cri-o://fdcb006a7cfafc04c9104016b73de2a96e361070388a78aae31e279b6b87dc35
    image: quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:74e4c487ba8ecc2c94f70e13242d6dc35791dcdcee5cfb2f30540535ea6f492f
    imageID: quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:74e4c487ba8ecc2c94f70e13242d6dc35791dcdcee5cfb2f30540535ea6f492f
    lastState:
      terminated:
        containerID: cri-o://fdcb006a7cfafc04c9104016b73de2a96e361070388a78aae31e279b6b87dc35
        exitCode: 124
        finishedAt: "2020-07-27T15:02:36Z"
        message: "43                [::ffff:127.0.0.1]:34830              \nESTAB
          \     0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:59288
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:45322
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:53198
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:33344
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:43514
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:55122
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:40244
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:35558
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:52876
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:59942
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:47006
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:50084
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:38228
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:43458
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:35598
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:60402
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:47488
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:60672
          \             \nESTAB      0      0       [::ffff:127.0.0.1]:9443                [::ffff:127.0.0.1]:55836
          \             ' ']'\n+ sleep 1\n"
        reason: Error
        startedAt: "2020-07-27T14:59:36Z"
    name: kube-controller-manager-recovery-controller
    ready: false
    restartCount: 268
    started: false
    state:
      waiting:
        message: back-off 5m0s restarting failed container=kube-controller-manager-recovery-controller
          pod=kube-controller-manager-os-mgr-1_openshift-kube-controller-manager(2b5ff4ae86d1763793ace6b7adb77767)
        reason: CrashLoopBackOff

*** This bug has been marked as a duplicate of bug 1858498 ***