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

Bug 1726995

Summary:

After UPI on VMware ; control-plane error container runtime network not ready

Product:

OpenShift Container Platform

Reporter:

florian.coulombel

Component:

Installer

Assignee:

Abhinav Dahiya <adahiya>

Installer sub component:

openshift-installer

QA Contact:

Johnny Liu <jialiu>

Status:

CLOSED NOTABUG

Docs Contact:

Severity:

medium

Priority:

unspecified

CC:

aos-bugs

Version:

4.1.0

Target Milestone:

---

Target Release:

4.1.z

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:

2019-07-09 09:37:53 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
kube logs and installation configuration	none

Description florian.coulombel 2019-07-04 08:40:32 UTC

Created attachment 1587318 [details]
kube logs and installation configuration

Description of problem:
Openshift installation is stalled because control-planes etcds are no accessible

Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. download the latest ova from : https://mirror.openshift.com/pub/openshift-v4/dependencies/rhcos/4.1/latest/rhcos-4.1.0-x86_64-vmware.ova
2. deploy the infrastructure with the help of terraform like describe in this post : https://blog.openshift.com/deploying-a-user-provisioned-infrastructure-environment-for-openshift-4-1-on-vsphere/ and 
3. wait for all the nodes (bootstrap, control-planes, workers) boot properly and what the progress with : openshift-install wait-for bootstrap-complete

Actual results:
The installation process blocks at step 3. with :
./openshift-install --dir ignition-configs/ wait-for bootstrap-complete --log-level debug
DEBUG OpenShift Installer v4.1.0-201905061832-dirty 
DEBUG Built from commit 9b486eedf57c20ce446b25734afc1187259a599e 
INFO Waiting up to 30m0s for the Kubernetes API at https://api.os4.flo.lss.emc.com:6443... 
DEBUG Still waiting for the Kubernetes API: Get https://api.os4.flo.lss.emc.com:6443/version?timeout=32s: x509: certificate has expired or is not yet valid

 
After some investigation, I validated bootstrap server works properly (no error in the logs). 
But when I check etcd from the control-planes, we can't see the etcd ports (cf. netstat logs), and we have the following error from journalctl -u kubelet :
Jul 03 12:19:59 control-plane-0 hyperkube[889]: E0703 12:19:59.257504     889 kubelet.go:2199] Container runtime network not ready: NetworkReady=false reason:NetworkPluginNotReady message:Network plugin returns error: cni config uninitialized
Jul 03 12:19:59 control-plane-0 hyperkube[889]: E0703 12:19:59.325362     889 kubelet.go:2273] node "control-plane-0" not found

From the control-plane we have the following containers : 
[root@control-plane-0 ~]# crictl ps -a
CONTAINER ID        IMAGE                                                              CREATED             STATE               NAME                ATTEMPT             POD ID
af34f750c40e1       8d90c989c9b587b2a9eed292165f9f3f99797e45b13d38f80b5247493714afef   21 hours ago        Running             certs               0                   17542220b613f
9ba697e808d55       683c4d7d20b15834120608a26b38fd75fe0759a7ab46faa81d176fd97df9ab72   21 hours ago        Exited              discovery           2                   17542220b613f

[root@control-plane-0 ~]# crictl logs af34f750c40e1 2>&1 >/dev/null | more
+ source /run/etcd/environment
++ ETCD_IPV4_ADDRESS=***.***.***.165
++ ETCD_DNS_NAME=etcd-0.os4.flo.lss.emc.com
++ ETCD_WILDCARD_DNS_NAME='*.os4.flo.lss.emc.com'
+ '[' -e /etc/ssl/etcd/system:etcd-server:etcd-0.os4.flo.lss.emc.com.crt -a -e /etc/ssl/etcd/system:etcd-server:etcd-0.os4.flo.lss.emc.com.key ']'
+ kube-client-agent request --kubeconfig=/etc/kubernetes/kubeconfig --orgname=system:etcd-servers --assetsdir=/etc/ssl/etcd '--dnsnames=localhost,etcd.kube-system.svc,etcd.kube-system.svc.cluster.local,etcd.openshift-etcd.svc,etcd.opensh
ift-etcd.svc.cluster.local,*.os4.flo.lss.emc.com' --commonname=system:etcd-server:etcd-0.os4.flo.lss.emc.com --ipaddrs=10.247.144.165,127.0.0.1
ERROR: logging before flag.Parse: E0703 11:23:20.175941       7 agent.go:116] error sending CSR to signer: Post https://api-int.os4.flo.lss.emc.com:6443/apis/certificates.k8s.io/v1beta1/certificatesigningrequests: x509: certificate has e
xpired or is not yet valid


Expected results:
The expected result will be that the install caries on

Additional info:
Installation logs, ignition files, load-balancer config, terraform vars and netstat logs are available in the attachment.

Comment 1 Casey Callendrello 2019-07-04 12:05:35 UTC

I don't think this is a networking issue - you will see that message until the control plane successfully bootstraps (which yours has not). Only then will pod networking come up, but this is failing long before that.

The certificate is failing to validate - is there a chance there is clock skew?

Over to the installer team for troubleshooting.

Comment 2 florian.coulombel 2019-07-08 08:46:55 UTC

Hi,
I tried to boot the servers in order 1st bootstrap then control-planes then compute nodes. It has the same result.

After doing a bit more of investigation I noticed an issue caused by SELinux

[core@bootstrap-0 ~]$ journalctl -b -f -u bootkube.service
-- Logs begin at Wed 2019-07-03 09:51:20 UTC. --
Jul 08 08:08:34 bootstrap-0 bootkube.sh[1090]: 11e2247ec3407da22b665c300a888f583273e33a7a6d24e5106ea78626cb54ee
Jul 08 08:08:34 bootstrap-0 systemd[1]: bootkube.service: Main process exited, code=exited, status=125/n/a
Jul 08 08:08:34 bootstrap-0 systemd[1]: bootkube.service: Failed with result 'exit-code'.
Jul 08 08:08:40 bootstrap-0 systemd[1]: bootkube.service: Service RestartSec=5s expired, scheduling restart.
Jul 08 08:08:40 bootstrap-0 systemd[1]: bootkube.service: Scheduled restart job, restart counter is at 1.
Jul 08 08:08:40 bootstrap-0 systemd[1]: Stopped Bootstrap a Kubernetes cluster.
Jul 08 08:08:40 bootstrap-0 systemd[1]: Started Bootstrap a Kubernetes cluster.
Jul 08 08:08:52 bootstrap-0 bootkube.sh[4249]: Starting etcd certificate signer...
Jul 08 08:08:52 bootstrap-0 bootkube.sh[4249]: 7f74363db9453b4b0871ebe9ecde70422e644b8a0a3a1ac26f4f2bf436c60fda
Jul 08 08:08:52 bootstrap-0 bootkube.sh[4249]: Waiting for etcd cluster...


[core@bootstrap-0 ~]$ crictl ps
FATA[0002] failed to connect: failed to connect, make sure you are running as root and the runtime has been started: context deadline exceeded 
[core@bootstrap-0 ~]$ sudo crictl ps
CONTAINER ID        IMAGE                                                              CREATED             STATE               NAME                    ATTEMPT             POD ID
6208ffde85e8f       c79234a31685c06aa27dd3f8fc7b2f5bcd5a5459747b08625c319252317be6e7   2 minutes ago       Running             machine-config-server   1                   6150fede8ac9e
[core@bootstrap-0 ~]$ sudo crictl ps -a
CONTAINER ID        IMAGE                                                                                                                    CREATED             STATE               NAME                        ATTEMPT             POD ID
6208ffde85e8f       c79234a31685c06aa27dd3f8fc7b2f5bcd5a5459747b08625c319252317be6e7                                                         2 minutes ago       Running             machine-config-server       1                   6150fede8ac9e
d17056e4c724a       ea59e30877e47c99a50708bdafebd283673cf2ac8308cec9db5c076cc0d4e76c                                                         2 minutes ago       Exited              machine-config-controller   1                   6150fede8ac9e
16dc1581b7cc8       quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:fbbdaeddbcc8906218c02adb8261e100235a7c8ee6aaf0173815316ea9d3b6d4   4 days ago          Exited              machine-config-server       0                   1c9358d46f6b8
[core@bootstrap-0 ~]$ crictl logs d17056e4c724a
E0708 08:11:13.205056    7628 remote_runtime.go:321] ContainerStatus "d17056e4c724a" from runtime service failed: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: permission denied"
FATA[0000] rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial unix /var/run/crio/crio.sock: connect: permission denied"


After setting SELinux to permissive (/etc/selinux/config) ; it moved to a further step :




-- Logs begin at Wed 2019-07-03 09:51:20 UTC. --
Jul 08 08:18:49 bootstrap-0 systemd[1]: Started Bootstrap a Kubernetes cluster.
Jul 08 08:19:02 bootstrap-0 bootkube.sh[1084]: Starting etcd certificate signer...
Jul 08 08:19:03 bootstrap-0 bootkube.sh[1084]: 6e61cebf1488192af0291c0ba73f5295d3751e3235e7406bfc5066bc579c4c84
Jul 08 08:19:03 bootstrap-0 bootkube.sh[1084]: Waiting for etcd cluster...
^C
[root@bootstrap-0 ~]# crictl ps -a
CONTAINER ID        IMAGE                                                              CREATED             STATE               NAME                        ATTEMPT             POD ID
8214baf1158a4       c79234a31685c06aa27dd3f8fc7b2f5bcd5a5459747b08625c319252317be6e7   3 minutes ago       Running             machine-config-server       3                   585753cf572b8
7de151c653dbb       ea59e30877e47c99a50708bdafebd283673cf2ac8308cec9db5c076cc0d4e76c   3 minutes ago       Exited              machine-config-controller   3                   585753cf572b8
48dd9dd6b1e19       c79234a31685c06aa27dd3f8fc7b2f5bcd5a5459747b08625c319252317be6e7   6 minutes ago       Exited              machine-config-server       2                   0f9069838d577
[root@bootstrap-0 ~]# 
[root@bootstrap-0 ~]# 
[root@bootstrap-0 ~]# crictl logs 8214baf1158a4
I0708 08:18:51.315525       1 bootstrap.go:37] Version: 4.1.0-201905070232-dirty
I0708 08:18:51.316095       1 api.go:51] launching server
I0708 08:18:51.316147       1 api.go:51] launching server
[root@bootstrap-0 ~]# crictl logs 7de151c653dbb
I0708 08:18:50.295568       1 bootstrap.go:40] Version: 4.1.0-201905070232-dirty
W0708 08:18:50.315641       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere
W0708 08:18:50.329541       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere
W0708 08:18:50.335681       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere
W0708 08:18:50.339155       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere
W0708 08:18:50.342760       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere
W0708 08:18:50.349190       1 render.go:127] Warning: the controller config referenced an unsupported platform: vsphere

machine-config-controller stopped with the warnings above


[root@bootstrap-0 ~]# podman ps -a
CONTAINER ID  IMAGE                                                COMMAND               CREATED        STATUS            PORTS  NAMES
2ae1cd1c55d1  quay.io/openshift-release-dev/ocp-v4.0-art-dev:none  etcdctl --dial-ti...  9 minutes ago  Up 9 minutes ago         etcdctl
6e61cebf1488  quay.io/openshift-release-dev/ocp-v4.0-art-dev:none  /usr/bin/kube-etc...  9 minutes ago  Up 9 minutes ago         etcd-signer


there are no logs from etcdctl.

From etcd-signer logs we can see it tries to connect on the load-balancer IP for every odd ports


[root@bootstrap-0 ~]# podman logs 6e61cebf1488
2019/07/08 08:19:12 http: TLS handshake error from ***.***.***.153:35412: remote error: tls: bad certificate
...
2019/07/08 08:38:31 http: TLS handshake error from  ***.***.***.153:60986: remote error: tls: bad certificate
2019/07/08 08:38:31 http: TLS handshake error from  ***.***.***.153:60988: remote error: tls: bad certificate
2019/07/08 08:38:31 http: TLS handshake error from  ***.***.***.153:60992: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:60994: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:32768: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:60998: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:32770: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:32772: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:60996: remote error: tls: bad certificate
2019/07/08 08:38:32 http: TLS handshake error from  ***.***.***.153:32774: remote error: tls: bad certificate


I can confirm there is a service listening on 6443 on the bootstrap server but not on the control-planes.

Any idea where it blocks ?

Comment 3 Johnny Liu 2019-07-09 02:28:12 UTC

Hope you notice this warning in official doc - https://docs.openshift.com/container-platform/4.1/installing/installing_vsphere/installing-vsphere.html#installation-generate-ignition-configs_installing-vsphere:

'''
The Ignition config files that the installation program generates contain certificates that expires after 24 hours. You must complete you cluster installation before the certificate expires.
'''

Comment 4 florian.coulombel 2019-07-09 09:37:53 UTC

That is it...

Thanks for the hint.