Bug 1780534

Summary: [IPI] [OSP] openshift-install got failed for floatingip creation if rhcos base image uploading take more than 10m0s
Product: OpenShift Container Platform Reporter: weiwei jiang <wjiang>
Component: InstallerAssignee: Mike Fedosin <mfedosin>
Installer sub component: openshift-installer QA Contact: weiwei jiang <wjiang>
Status: CLOSED ERRATA Docs Contact:
Severity: medium    
Priority: high CC: eduen, mfedosin, pprinett
Version: 4.3.0Keywords: Reopened
Target Milestone: ---Flags: eduen: needinfo? (mfedosin)
Target Release: 4.4.0   
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-05-04 11:18:37 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:
Bug Depends On:    
Bug Blocks: 1810018    

Description weiwei jiang 2019-12-06 10:07:42 UTC
Description of problem:
openshift-install got failed if rhcos base image upload take more than 10m0s to upload 
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [9m40s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m20s elapsed]"
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [9m50s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m30s elapsed]"
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [10m0s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m40s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m50s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [11m0s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Creation complete after 11m8s [id=06881570-3772-44b7-a288-025e85eda912]"
level=debug msg="data.openstack_images_image_v2.base_image: Refreshing state..."
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creating..."
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [10s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [30s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [30s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [50s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [50s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [50s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [50s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creation complete after 1m1s [id=3d0135f5-b182-43e6-a33a-aed42c75ed95]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creation complete after 1m3s [id=a315e92e-4bd1-469d-b584-29ff35dff579]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creation complete after 1m3s [id=7edc5a1b-2970-4f75-9f35-613f95800b2d]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [1m10s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creation complete after 1m13s [id=af06cfb2-37e4-4eb4-857e-93867f3cec74]"
level=error
level=error msg="Error: Error waiting for openstack_networking_floatingip_v2 926cc4a4-7adb-45d9-8f06-df644c8356f8 to become available: timeout while waiting for state to become 'ACTIVE, DOWN' (timeout: 10m0s)"
level=error
level=error msg="  on ../../../../../tmp/openshift-install-994566403/bootstrap/main.tf line 27, in resource \"openstack_networking_floatingip_v2\" \"bootstrap_fip\":"
level=error msg="  27: resource \"openstack_networking_floatingip_v2\" \"bootstrap_fip\" {"
level=error
level=error
level=fatal msg="failed to fetch Cluster: failed to generate asset \"Cluster\": failed to create cluster: failed to apply using Terraform"


Version-Release number of the following components:
4.3.0-0.nightly-2019-12-06-014514

How reproducible:
It happen when rhcos base image take more than 10m0s to upload

Steps to Reproduce:
1. Create ipi on osp cluster and make rhcos base image uploading take more than 10m0s
2.
3.

Actual results:
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m20s elapsed]"
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [9m50s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m30s elapsed]"
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [10m0s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m40s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [10m50s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Still creating... [11m0s elapsed]"
level=debug msg="openstack_images_image_v2.base_image[0]: Creation complete after 11m8s [id=06881570-3772-44b7-a288-025e85eda912]"
level=debug msg="data.openstack_images_image_v2.base_image: Refreshing state..."
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creating..."
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [10s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [30s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [30s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [50s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [50s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [50s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [50s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [1m0s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creation complete after 1m1s [id=3d0135f5-b182-43e6-a33a-aed42c75ed95]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creation complete after 1m3s [id=a315e92e-4bd1-469d-b584-29ff35dff579]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creation complete after 1m3s [id=7edc5a1b-2970-4f75-9f35-613f95800b2d]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [1m10s elapsed]"
level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creation complete after 1m13s [id=af06cfb2-37e4-4eb4-857e-93867f3cec74]"
level=error
level=error msg="Error: Error waiting for openstack_networking_floatingip_v2 926cc4a4-7adb-45d9-8f06-df644c8356f8 to become available: timeout while waiting for state to become 'ACTIVE, DOWN' (timeout: 10m0s)"
level=error
level=error msg="  on ../../../../../tmp/openshift-install-994566403/bootstrap/main.tf line 27, in resource \"openstack_networking_floatingip_v2\" \"bootstrap_fip\":"
level=error msg="  27: resource \"openstack_networking_floatingip_v2\" \"bootstrap_fip\" {"
level=error
level=error
level=fatal msg="failed to fetch Cluster: failed to generate asset \"Cluster\": failed to create cluster: failed to apply using Terraform"

Expected results:
It should not fail

Additional info:
Please attach logs from ansible-playbook with the -vvv flag

Comment 1 Mike Fedosin 2019-12-06 13:48:54 UTC
I hit this issue yesterday as well. This happenned because there were no floating ips available in the network, and there is no problem if image uploading takes more than 10 minutes. The record for me is 30+ minutes, with a successful installation after that.

Comment 4 Mike Fedosin 2019-12-10 19:24:37 UTC
Yes, I was able to reproduce it... I apologize for closing that bug earlier. This is a weird regression, because a couple of weeks ago it worked well, even after 30 minutes. 
After a little research, it's clear why we get this error - we create a fip and wait the bootstrap machine to become available. When image uploading takes more than 10 minutes, we can't attach the fip to the machine in time and the installation fails.
Looks like these timeouts were introduced in Terraform recently, because previously we didn't see them.
The fix is trivial, it should be available today.

Comment 6 weiwei jiang 2020-01-06 03:06:29 UTC
Checked with 4.4.0-0.nightly-2020-01-05-221122, It's fixed now.

level=debug msg="openstack_images_image_v2.base_image[0]: Creation complete after 11m38s [id=deec1c34-c73c-4287-872a-c30327379c55]"
level=debug msg="data.openstack_images_image_v2.base_image: Refreshing state..."

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creating..."

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [10s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [10s elapsed]"

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [20s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [20s elapsed]"

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [30s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [30s elapsed]"

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Still creating... [40s elapsed]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Still creating... [40s elapsed]"

level=debug msg="module.bootstrap.openstack_compute_instance_v2.bootstrap: Creation complete after 44s [id=4c8c574a-5776-46ce-95f9-fff4388e7502]"
level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Creating..."
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[2]: Creation complete after 44s [id=ab615cb5-150f-47e3-af79-6c5c7d13fc33]"

level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[1]: Creation complete after 45s [id=8ab4391a-61fd-44dd-b1a0-4136706238ff]"
level=debug msg="module.masters.openstack_compute_instance_v2.master_conf[0]: Creation complete after 45s [id=018a60b0-20e7-4370-9358-7372e34823fc]"

level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Still creating... [10s elapsed]"

level=debug msg="module.bootstrap.openstack_networking_floatingip_v2.bootstrap_fip: Creation complete after 12s [id=a502e1cd-6728-4969-a0ab-6235a4de5de4]"

Comment 8 errata-xmlrpc 2020-05-04 11:18:37 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:0581