Secrets "v4-0-config-system-router-certs" not found for cluster-authentication operator

[praveenkumar]

Not able to start the auth service because of "v4-0-config-system-router-certs" not found error.

$ openshift-install version
openshift-install unreleased-master-577-g9777df02d2a0dc287bb520c5ea2f409499c28eca
built from commit 9777df02d2a0dc287bb520c5ea2f409499c28eca

$ oc get co
NAME                                  VERSION                           AVAILABLE   PROGRESSING   FAILING   SINCE
authentication                                                          False       False         True      5m15s
cluster-autoscaler                    4.0.0-0.alpha-2019-03-18-221255   True        False         False     19m
dns                                   4.0.0-0.alpha-2019-03-18-221255   True        False         False     24m
kube-apiserver                        4.0.0-0.alpha-2019-03-18-221255   True        False         False     21m
kube-controller-manager               4.0.0-0.alpha-2019-03-18-221255   True        False         False     18m
kube-scheduler                        4.0.0-0.alpha-2019-03-18-221255   True        False         False     20m
machine-api                           4.0.0-0.alpha-2019-03-18-221255   True        False         False     25m
machine-config                        4.0.0-0.alpha-2019-03-18-221255   True        False         False     24m
network                               4.0.0-0.alpha-2019-03-18-221255   True        False         False     25m
node-tuning                           4.0.0-0.alpha-2019-03-18-221255   True        False         False     16m
openshift-apiserver                   4.0.0-0.alpha-2019-03-18-221255   True        False         False     18m
openshift-cloud-credential-operator   4.0.0-0.alpha-2019-03-18-221255   True        False         False     24m
openshift-controller-manager          4.0.0-0.alpha-2019-03-18-221255   True        False         False     18m
operator-lifecycle-manager            4.0.0-0.alpha-2019-03-18-221255   True        False         False     25m
service-ca                                                              True        False         False     18m
service-catalog-apiserver             4.0.0-0.alpha-2019-03-18-221255   True        False         False     17m
service-catalog-controller-manager    4.0.0-0.alpha-2019-03-18-221255   True        False         False     17m

$ oc get co authentication -oyaml
apiVersion: config.openshift.io/v1
kind: ClusterOperator
metadata:
  creationTimestamp: 2019-03-19T05:42:40Z
  generation: 1
  name: authentication
  resourceVersion: "15617"
  selfLink: /apis/config.openshift.io/v1/clusteroperators/authentication
  uid: cf8b6794-4a09-11e9-b47e-664f163f5f0f
spec: {}
status:
  conditions:
  - lastTransitionTime: 2019-03-19T05:42:40Z
    message: 'Failing: secrets "v4-0-config-system-router-certs" not found'
    reason: Failing
    status: "True"
    type: Failing
  - lastTransitionTime: 2019-03-19T05:42:40Z
    reason: AsExpected
    status: "False"
    type: Progressing
  - lastTransitionTime: 2019-03-19T05:42:40Z
    reason: Available
    status: "False"
    type: Available
  - lastTransitionTime: 2019-03-19T05:42:40Z
    reason: NoData
    status: Unknown
    type: Upgradeable
  extension: null
  relatedObjects:
  - group: operator.openshift.io
    name: cluster
    resource: authentications
  - group: config.openshift.io
    name: cluster
    resource: authentications
  - group: config.openshift.io
    name: cluster
    resource: oauths
  - group: ""
    name: openshift-config
    resource: namespaces
  - group: ""
    name: openshift-config-managed
    resource: namespaces
  - group: ""
    name: openshift-authentication
    resource: namespaces
  - group: ""
    name: openshift-authentication-operator
    resource: namespaces
  versions: null

$ oc get pods --all-namespaces| grep -i auth
openshift-authentication-operator                       openshift-authentication-operator-7d69d9795-nds62                 1/1     Running     0          2m55s

$ oc logs openshift-authentication-operator-7d69d9795-kwnv5 -n openshift-authentication-operator
W0319 05:42:23.713608       1 cmd.go:134] Using insecure, self-signed certificates
I0319 05:42:23.714007       1 crypto.go:493] Generating new CA for cluster-authentication-operator-signer@1552974143 cert, and key in /tmp/serving-cert-030527269/serving-signer.crt, /tmp/serving-cert-030527269/serving-signer.key
I0319 05:42:24.737477       1 observer_polling.go:106] Starting file observer
W0319 05:42:25.221662       1 authorization.go:47] Authorization is disabled
W0319 05:42:25.221769       1 authentication.go:55] Authentication is disabled
I0319 05:42:25.223943       1 secure_serving.go:116] Serving securely on 0.0.0.0:8443
I0319 05:42:25.224768       1 leaderelection.go:205] attempting to acquire leader lease  openshift-authentication-operator/cluster-authentication-operator-lock...
I0319 05:42:40.782056       1 leaderelection.go:214] successfully acquired lease openshift-authentication-operator/cluster-authentication-operator-lock
I0319 05:42:40.790265       1 event.go:221] Event(v1.ObjectReference{Kind:"ConfigMap", Namespace:"openshift-authentication-operator", Name:"cluster-authentication-operator-lock", UID:"177c52f7-4a08-11e9-b47e-664f163f5f0f", APIVersion:"v1", ResourceVersion:"15612", FieldPath:""}): type: 'Normal' reason: 'LeaderElection' c6383bf3-4a09-11e9-aeee-0a580a80003d became leader
I0319 05:42:40.810675       1 status_controller.go:173] Starting StatusSyncer-authentication
I0319 05:42:40.820314       1 resourcesync_controller.go:207] Starting ResourceSyncController
I0319 05:42:40.827469       1 event.go:221] Event(v1.ObjectReference{Kind:"Deployment", Namespace:"openshift-authentication-operator", Name:"openshift-authentication-operator", UID:"081df1fe-4a08-11e9-b47e-664f163f5f0f", APIVersion:"apps/v1", ResourceVersion:"", FieldPath:""}): type: 'Warning' reason: 'StatusNotFound' Unable to determine current operator status for authentication
I0319 05:42:40.828105       1 controller.go:54] Starting AuthenticationOperator2
I0319 05:42:40.865859       1 status_controller.go:98] clusteroperator/authentication not found
I0319 05:42:40.875153       1 status_controller.go:150] clusteroperator/authentication diff {"status":{"conditions":[{"lastTransitionTime":"2019-03-19T05:42:40Z","message":"Failing: secrets \"v4-0-config-system-router-certs\" not found","reason":"Failing","status":"True","type":"Failing"},{"lastTransitionTime":"2019-03-19T05:42:40Z","reason":"AsExpected","status":"False","type":"Progressing"},{"lastTransitionTime":"2019-03-19T05:42:40Z","reason":"Available","status":"False","type":"Available"},{"lastTransitionTime":"2019-03-19T05:42:40Z","reason":"NoData","status":"Unknown","type":"Upgradeable"}],"relatedObjects":[{"group":"operator.openshift.io","name":"cluster","resource":"authentications"},{"group":"config.openshift.io","name":"cluster","resource":"authentications"},{"group":"config.openshift.io","name":"cluster","resource":"oauths"},{"group":"","name":"openshift-config","resource":"namespaces"},{"group":"","name":"openshift-config-managed","resource":"namespaces"},{"group":"","name":"openshift-authentication","resource":"namespaces"},{"group":"","name":"openshift-authentication-operator","resource":"namespaces"}]}}
E0319 05:42:41.217898       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:41.417729       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:41.617912       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:41.819724       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:42.021670       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:42.219946       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:42.421906       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:42.772591       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:43.435065       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:44.732913       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:47.326001       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:42:52.468559       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:43:02.729566       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
E0319 05:43:23.228771       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found

[wking]

I see this in CI too:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-authentication-operator_openshift-authentication-operator-6548bcfb48-b2scr_operator.log.gz | gunzip | grep '^E'
E0319 14:58:50.103266       1 controller.go:130] {🐼 🐼} failed with: Operation cannot be fulfilled on authentications.operator.openshift.io "cluster": the object has been modified; please apply your changes to the latest version and try again
E0319 14:58:50.501338       1 controller.go:130] {🐼 🐼} failed with: secrets "v4-0-config-system-router-certs" not found
...

In my case, it eventually surfaced as:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-a
ws/4532/artifacts/e2e-aws/pods/openshift-console_console-7f655c4974-mrq4p_console_previous.log.gz | gunzip | tail -n1
2019/03/19 15:21:39 auth: error contacting auth provider (retrying in 10s): discovery through endpoint https://172.30.0.1:443/.well-known/oauth-authorization-server failed: 404 Not Found

and triggered:

fail [github.com/openshift/origin/test/extended/operators/cluster.go:109]: Expected
    <[]string | len:2, cap:2>: [
        "Pod openshift-console/console-7f655c4974-mrq4p is not healthy: container console has restarted more than 5 times",
        "Pod openshift-console/console-7f655c4974-nlh2w is not healthy: container console has restarted more than 5 times",
    ]
to be empty

[wking]

@enj pointed out that the certs come from ingress, and in my case the ingress operator started very late:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-ingress-operator_ingress-operator-66cc97d7bf-cfggf_ingress-operator.log.gz | gunzip | head -n1
2019-03-19T15:22:32.161Z    INFO    operator    log/log.go:26    started zapr logger

and had the certs out very quickly after that:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-ingress-operator_ingress-operator-66cc97d7bf-cfggf_ingress-operator.log.gz | gunzip | grep 'Published router certificates'
2019-03-19T15:22:33.866Z	DEBUG	operator.init.kubebuilder.manager.events	recorder/recorder.go:53	Normal	{"object": {"kind":"Secret","namespace":"openshift-config-managed","name":"router-certs","uid":"d1c7abcb-4a5a-11e9-8b3b-126e53c8f1fa","apiVersion":"v1","resourceVersion":"26640"}, "reason": "PublishedRouterCertificates", "message": "Published router certificates"}

So not a console or auth issue.

/close

[openshift-ci-robot]

@wking: Closing this issue.

In response to this:

@enj pointed out that the certs come from ingress, and in my case the ingress operator started very late:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-ingress-operator_ingress-operator-66cc97d7bf-cfggf_ingress-operator.log.gz | gunzip | head -n1
2019-03-19T15:22:32.161Z    INFO    operator    log/log.go:26    started zapr logger

and had the certs out very quickly after that:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-ingress-operator_ingress-operator-66cc97d7bf-cfggf_ingress-operator.log.gz | gunzip | grep 'Published router certificates'
2019-03-19T15:22:33.866Z	DEBUG	operator.init.kubebuilder.manager.events	recorder/recorder.go:53	Normal	{"object": {"kind":"Secret","namespace":"openshift-config-managed","name":"router-certs","uid":"d1c7abcb-4a5a-11e9-8b3b-126e53c8f1fa","apiVersion":"v1","resourceVersion":"26640"}, "reason": "PublishedRouterCertificates", "message": "Published router certificates"}

So not a console or auth issue.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[wking]

The issue has something to do with delays for some resources during CVO roll-out. GitHub doesn't support inline SVGs, so this isn't interactive, but:

Here's the SVG for folks who want to view it locally: cvo.svg.txt.

The slow objects:

$ grep 'width="[0-9][0-9][0-9][0-9]' cvo.svg
 <rect x="0.053627" y="292" width="1506.327718" height="4" fill="blue"><title>servicemonitor openshift-kube-scheduler-operator/kube-scheduler-operator 301/308 (0:25:06.327718)</title></rect>
 <rect x="0.053747" y="296" width="1507.264621" height="4" fill="blue"><title>servicemonitor openshift-controller-manager-operator/openshift-controller-manager-operator 307/308 (0:25:07.264621)</title></rect>
 <rect x="0.055222" y="316" width="1507.238081" height="4" fill="blue"><title>servicemonitor openshift-kube-apiserver-operator/kube-apiserver-operator 295/308 (0:25:07.238081)</title></rect>
 <rect x="0.061379" y="320" width="1507.756473" height="4" fill="blue"><title>servicemonitor openshift-kube-controller-manager-operator/kube-controller-manager-operator 298/308 (0:25:07.756473)</title></rect>
 <rect x="0.064809" y="388" width="1507.62846" height="4" fill="blue"><title>servicemonitor openshift-apiserver-operator/openshift-apiserver-operator 304/308 (0:25:07.628460)</title></rect>
 <rect x="0.983909" y="504" width="1508.813288" height="4" fill="blue"><title>rolebinding openshift-cluster-storage-operator/cluster-storage-operator 229/308 (0:25:08.813288)</title></rect>
 <rect x="6.329864" y="812" width="1503.218897" height="4" fill="blue"><title>rolebinding openshift-ingress-operator/ingress-operator 189/308 (0:25:03.218897)</title></rect>
 <rect x="26.910242" y="936" width="1481.558137" height="4" fill="blue"><title>servicemonitor openshift-image-registry/image-registry 286/308 (0:24:41.558137)</title></rect>
 <rect x="27.116099" y="964" width="1480.551961" height="4" fill="blue"><title>servicemonitor openshift-service-catalog-apiserver-operator/openshift-service-catalog-apiserver-operator 289/308 (0:24:40.551961)</title></rect>
 <rect x="27.265212" y="972" width="1480.078164" height="4" fill="blue"><title>servicemonitor openshift-service-catalog-controller-manager-operator/openshift-service-catalog-controller-manager-operator 292/308 (0:24:40.078164)</title></rect>
 <rect x="27.887874" y="1012" width="1501.151953" height="4" fill="blue"><title>clusteroperator authentication 154/308 (0:25:01.151953)</title></rect>
 <rect x="29.428165" y="1084" width="1609.796623" height="4" fill="blue"><title>clusteroperator monitoring 199/308 (0:26:49.796623)</title></rect>

Logs for the ingress rolebinding:

$ curl -s https://storage.googleapis.com/origin-ci-test/pr-logs/pull/openshift_installer/1432/pull-ci-openshift-installer-master-e2e-aws/4532/artifacts/e2e-aws/pods/openshift-cluster-version_cluster-version-operator-7759674cb6-5lf6m_cluster-version-operator.log.gz | gunzip | grep 'rolebinding "openshift-ingress-operator/ingress-operator"'
I0319 14:57:15.055171       1 sync_worker.go:462] Running sync for rolebinding "openshift-ingress-operator/ingress-operator" (189 of 308)
E0319 14:57:15.204004       1 task.go:58] error running apply for rolebinding "openshift-ingress-operator/ingress-operator" (189 of 308): rolebindings.rbac.authorization.k8s.io "ingress-operator" is forbidden: the server could not find the requested resource (get rolebindingrestrictions.authorization.openshift.io)
...
E0319 14:57:22.503107       1 task.go:58] error running apply for rolebinding "openshift-ingress-operator/ingress-operator" (189 of 308): rolebindings.rbac.authorization.k8s.io "ingress-operator" is forbidden: the server could not find the requested resource (get rolebindingrestrictions.authorization.openshift.io)
I0319 15:21:45.157019       1 task_graph.go:566] Result of work: [Could not update rolebinding "openshift-cluster-storage-operator/cluster-storage-operator" (229 of 308): the server has forbidden updates to this resource...
...
I0319 15:22:16.937922       1 sync_worker.go:462] Running sync for rolebinding "openshift-ingress-operator/ingress-operator" (189 of 308)
I0319 15:22:18.274068       1 sync_worker.go:475] Done syncing for rolebinding "openshift-ingress-operator/ingress-operator" (189 of 308)
...

@enj has some idea what's going on with those, although this is all beyond me ;).