Bug 1828948

Summary: show users actual error when API fails to come up
Product: OpenShift Container Platform Reporter: Abhinav Dahiya <adahiya>
Component: InstallerAssignee: Abhinav Dahiya <adahiya>
Installer sub component: openshift-installer QA Contact: jima
Status: CLOSED ERRATA Docs Contact:
Severity: high    
Priority: high CC: jialiu, jima
Version: 4.5   
Target Milestone: ---   
Target Release: 4.4.z   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1828947 Environment:
Last Closed: 2020-05-26 16:50:33 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On: 1828947    
Bug Blocks:    

Description Abhinav Dahiya 2020-04-28 16:04:18 UTC 
+++ This bug was initially created as a clone of Bug #1828947 +++

Description of problem:

previously all the errors were context Deadline exceeded, with this change the error returned is the last tracked error.

This is useful as the user has more information about what the failure could be.

For example, BZ https://bugzilla.redhat.com/show_bug.cgi?id=1810318#c8
the `.openshift_install.log` had the following debug log.
```
time="2020-03-04T21:08:13Z" level=debug msg="Still waiting for the Kubernetes API: Get https://api.openshift10.az.test-am-cloudpak.io:6443/version?timeout=32s: dial tcp: lookup api.openshift10.az.test-am-cloudpak.io on 127.0.0.53:53: no such host"
```
but the error returned to the use was
```
FATAL Bootstrap failed to complete: waiting for Kubernetes API: context deadline exceeded
```

returning the last tracked error would help users as they don't have to look into log file for most errors.

Version-Release number of the following components:
rpm -q openshift-ansible
rpm -q ansible
ansible --version

How reproducible:

Steps to Reproduce:
1.
2.
3.

Actual results:
Please include the entire output from the last TASK line through the end of output if an error is generated

Expected results:

Additional info:
Please attach logs from ansible-playbook with the -vvv flag
Comment 4 jima 2020-05-18 04:02:34 UTC 
Issue is verified on 4.4.0-0.nightly-2020-05-17-221856.
During installation, removing nameserver from Hosted Zone "qe.devcluster.openshift.com" on route53, so that dns records could not be parsed during waiting for API running and installation failed.

In .openshift_install.log file:
time="2020-05-17T23:26:00-04:00" level=info msg="Waiting up to 20m0s for the Kubernetes API at https://api.jima-1828948.qe.devcluster.openshift.com:6443..."
time="2020-05-17T23:26:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:26:30-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:27:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:27:30-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:28:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:28:30-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:29:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:29:30-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:30:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:30:30-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:31:00-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:31:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:32:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:32:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:33:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:33:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:34:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:34:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:35:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:35:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:36:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:36:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:37:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:37:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:38:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:38:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:39:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:39:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:40:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:40:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:41:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:41:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:42:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:42:31-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:43:01-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:43:32-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:44:02-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:44:32-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:45:02-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:45:32-04:00" level=debug msg="Still waiting for the Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:46:00-04:00" level=error msg="Attempted to gather ClusterOperator status after wait failure: listing ClusterOperator objects: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/apis/config.openshift.io/v1/clusteroperators: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
time="2020-05-17T23:46:00-04:00" level=info msg="Use the following commands to gather logs from the cluster"
time="2020-05-17T23:46:00-04:00" level=info msg="openshift-install gather bootstrap --help"
time="2020-05-17T23:46:00-04:00" level=fatal msg="failed waiting for Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"


The latest error in .openshift_install.log is returned and shown on console ouptupt:
level=info msg="Waiting up to 20m0s for the Kubernetes API at https://api.jima-1828948.qe.devcluster.openshift.com:6443..."
level=error msg="Attempted to gather ClusterOperator status after wait failure: listing ClusterOperator objects: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/apis/config.openshift.io/v1/clusteroperators: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
level=info msg="Use the following commands to gather logs from the cluster"
level=info msg="openshift-install gather bootstrap --help"
level=fatal msg="failed waiting for Kubernetes API: Get https://api.jima-1828948.qe.devcluster.openshift.com:6443/version?timeout=32s: dial tcp: lookup api.jima-1828948.qe.devcluster.openshift.com on 10.11.142.1:53: no such host"
Comment 6 errata-xmlrpc 2020-05-26 16:50:33 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, 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/RHBA-2020:2180