Bug 1687241 - [OSP] Sometimes bootstrap and api fail to dial openstack metadata server during booting even with correct security group
Summary: [OSP] Sometimes bootstrap and api fail to dial openstack metadata server duri...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Installer
Version: 4.1.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: 4.2.0
Assignee: Tomas Sedovic
QA Contact: Tomas Sedovic
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-03-11 03:16 UTC by weiwei jiang
Modified: 2019-08-09 09:28 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-08-09 09:28:17 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description weiwei jiang 2019-03-11 03:16:18 UTC
Description of problem:
Trying to setup OCP on OSP with installer, but sometimes bootstrap and api fail to dial openstack metadata server during booting even with correct security group.

(openstack) server show wjiang-ocp-2k77q-bootstrap                                                                                                                                                                                           
+-----------------------------+--------------------------------------------------------------------------+                                                                                                                                   
| Field                       | Value                                                                    |                                                                                                                                   
+-----------------------------+--------------------------------------------------------------------------+                                                                                                                                   
| OS-DCF:diskConfig           | MANUAL                                                                   |                                                                                                                                   
| OS-EXT-AZ:availability_zone | nova                                                                     |                                                                                                                                   
| OS-EXT-STS:power_state      | Running                                                                  |                                                                                                                                   
| OS-EXT-STS:task_state       | None                                                                     |                                                                                                                                   
| OS-EXT-STS:vm_state         | active                                                                   |                                                                                                                                   
| OS-SRV-USG:launched_at      | 2019-03-11T02:39:37.000000                                               |
| OS-SRV-USG:terminated_at    | None                                                                     |                                                                                                                                   
| accessIPv4                  |                                                                          |
| accessIPv6                  |                                                                          |                                                                                                                                   
| addresses                   | wjiang-ocp-2k77q-openshift=192.168.0.6                                   |
| config_drive                |                                                                          |                                                                                                                                   
| created                     | 2019-03-11T02:39:02Z                                                     |
| flavor                      | m1.medium (2550ff80-8b69-4697-b020-f8c22ed33495)                         |                                                                                                                                   
| hostId                      | 1f4133f0b351ce8d1d7ccec7f2b07f33765d868d038120c83f0a23d4                 |
| id                          | 80d1ac91-5d07-4ded-995e-c9f345327329                                     |                                                                                                                                   
| image                       | 5efa4555-5f3f-4dbc-9434-845c9c115fcd                                     |
| key_name                    | None                                                                     |                                                                                                                                   
| name                        | wjiang-ocp-2k77q-bootstrap                                               |
| progress                    | 0                                                                        |                                                                                                                                   
| project_id                  | 542c6ebd48bf40fa857fc245c7572e30                                         |
| properties                  | Name='wjiang-ocp-2k77q-bootstrap', openshiftClusterID='wjiang-ocp-2k77q' |                                                                                                                                   
| security_groups             | name='wjiang-ocp-2k77q-master'                                           |
| status                      | ACTIVE                                                                   |                                                                                                                                   
| updated                     | 2019-03-11T02:39:37Z                                                     |                                                                                                                                   
| user_id                     | d57c957cb3c7010f14a049b72bbfd93d22c1cba255c3c2aa34be30ce5f83da7e         |                                                                                                                                   
| volumes_attached            |                                                                          |                                                                                                                                   
+-----------------------------+--------------------------------------------------------------------------+   

Following is the bootstrap boot log:(only focus on ignition here)

[    5.393297] systemd[1]: Starting Ignition (disks)...                                                                                                                                                                                                                                                                                                                                                                                                                             [0/1748]
[    5.448138] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #1
[    5.487508] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    5.517872] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #2
[    5.555615] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    5.710300] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #3
[    5.710575] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    6.510580] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #4
[    6.516581] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    8.111087] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #5
[    8.117235] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   11.311575] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #6                                          
[   14.326213] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[   19.327274] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #7                 
[   22.332084] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[   27.332382] ignition[484]: GET http://169.254.169.254/openstack/latest/user_data: attempt #8
[   30.338065] ignition[484]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[   35.106929] ignition[484]: neither config drive nor metadata service were available in time. Continuing without a config...
[   35.117494] ignition[484]: timed out while fetching config from config drive (config-2)
[   35.124678] ignition[484]: timed out while fetching config from config drive (CONFIG-2)                                                                                   
[[32m  OK  [0m] Started Ignition (disks).
[   35.131867] ignition[484]: failed to fetch config: not a config (empty)
[   35.135825] systemd[1]: Started Ignition (disks).
[   35.139409] ignition[484]: not a config (empty): ignoring user-provided config
[   35.144879] ignition[484]: reading system config file "/usr/lib/ignition/default.ign"
[   35.150297] ignition[484]: no config at "/usr/lib/ignition/default.ign"
[   35.153613] ignition[484]: disks: op(1): [started]  waiting for udev to settle
[   35.158010] ignition[484]: disks: op(1): [finished] waiting for udev to settle    
[   35.162235] ignition[484]: disks: disks passed                      
[   35.164774] ignition[484]: Ignition finished successfully
         Starting Ignition (files)...                                                          
[   73.141259] systemd[1]: Starting Ignition (files)...                                                                                                     
[   73.180945] ignition[1640]: INFO     : Ignition 0.28.0                                      
[   73.184736] ignition[1640]: INFO     : reading system config file "/usr/lib/ignition/base.ign"                                                           
[   73.190341] ignition[1640]: INFO     : no config at "/usr/lib/ignition/base.ign"            
[   73.195117] ignition[1640]: DEBUG    : parsed url from cmdline: ""                                                                                       
[   73.199920] ignition[1640]: INFO     : no config URL provided                               
[   73.203755] ignition[1640]: INFO     : reading system config file "/usr/lib/ignition/user.ign"                                                           
[   73.208831] ignition[1640]: INFO     : no config at "/usr/lib/ignition/user.ign"            
[   73.213871] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #1                                                 
[   73.220728] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   73.227158] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                             
[   74.183804] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   74.191843] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                             
[   75.184337] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   75.190160] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                             
[   76.184760] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                  
[   76.195260] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   76.201465] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[   76.397023] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #2
[   77.185006] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   77.191016] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   78.185443] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[[31m*[1;31m*[[   78.193141] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
0m[31m*   [0m] A start job is running for Ignition (files) (1min 15s / no limit)[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 15s / no limit)[   79.185691] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   79.193133] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[K[[   79.204354] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[0m[31m*     [0m] A start job is running for Ignition (files) (1min 16s / no limit)[   79.604899] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #3
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 16s / no limit)[K[   80.185886] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 17s / no limit)[   80.194761] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 17s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m[   81.186563] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
] A start job is running for Ignition (files) (1min 18s / no limit)[   81.194521] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 18s / no limit)[K[    [31m*[1;31m*[0m] A start job is r[   82.186847] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
unning for Ignition (files) (1min 19s / no limit)[   82.194843] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   82.210729] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[K[     [31m*[0m] A start job is running for Ignition (files) (1min 19s / no limit)[   83.011125] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #4
[K[    [31m*[1;31m*[0m] A start job is running for Ignition (files) (1min 20s / no limit)[   83.188802] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   83.196627] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 20s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 21s / no limit)[   84.193071] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   84.209174] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 21s / no limit)[   84.962283] random: crng init done
[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 22s / no limit)[   85.193263] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   85.200947] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   85.222497] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 22s / no limit)[K[[0m[31m*     [0m] A start job is running for Ignition (files) (1min 23s / no limit)[   86.193576] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   86.205962] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 23s / no limit)[   86.822927] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #5
[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 24s / no limit)[   87.193833] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   87.201624] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 24s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 25s / no limit)[   88.195078] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   88.201762] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   88.229958] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 25s / no limit)[K[    [31m*[1;31m*[0m] A start job is running for Ignition (files) (1min 26s / no limit)[   89.195341] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   89.202727] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                                                                                                                                            
[K[     [31m*[0m] A start job is running for Ignition (files) (1min 26s / no limit)[K[    [31m*[1;31m*[0m] A start job is running for Ignition (files) (1min 27s / no limit)[   90.195657] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   90.202478] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                            
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 27s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 28s / no limit)[   91.195887] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   91.203046] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                                                              
[   91.430256] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #6                                                                                               
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 28s / no limit)[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 29s / no limit)[   92.196156] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   92.202212] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                                   
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 29s / no limit)[K[[0m[31m*     [0m] A start job is running for Ignition (files) (1min 30s / no limit)[   93.196385] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                                                                                                                                                             
[   93.202422] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                 
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 30s / no limit)[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 31s / no limit)[   94.196572] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   94.201952] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                                                  
[   94.436070] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host                                
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 31s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 32s / no limit)[   95.196876] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   95.204452] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                                                                                                                                                                
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 32s / no limit)[K[    [31m*[1;31m*[0m] A start job is running for Ignition (files) (1min 33s / no limit)[   96.197416] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   96.203283] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                         
[K[     [31m*[0m] A start job is running for Ignition (files) (1min 33s / no limit)[K[    [31m*[1;31m*[0m] A start job is running for Ignition (files) (1min 34s / no limit)[   97.198062] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   97.204402] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 34s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 35s / no limit)[   98.198719] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[   98.205030] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                                                                                                                                                                                                                                                                                                                                               
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 35s / no limit)[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 36s / no limit)[   99.199058] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[   99.207100] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                                                           
[   99.436630] ignition[1640]: INFO     : GET http://169.254.169.254/openstack/latest/user_data: attempt #7                                                                                                 
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 36s / no limit)[K[[0m[31m*     [0m] A start job is running for Ignition (files) (1min 37s / no limit)[  100.199329] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[  100.205615] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                                                                                                                                                                                                                                                                                                                                               
[K[[1;31m*[0m[31m*    [0m] A start job is running for Ignition (files) (1min 37s / no limit)[K[[31m*[1;31m*[0m[31m*   [0m] A start job is running for Ignition (files) (1min 38s / no limit)[  101.200647] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...
[  101.208191] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...                                                         
[K[ [31m*[1;31m*[0m[31m*  [0m] A start job is running for Ignition (files) (1min 38s / no limit)[K[  [31m*[1;31m*[0m[31m* [0m] A start job is running for Ignition (files) (1min 39s / no limit)[  102.200824] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/config-2") not found. Waiting...                                                                                                                                                                               
[  102.206959] ignition[1640]: DEBUG    : config drive ("/dev/disk/by-label/CONFIG-2") not found. Waiting...
[  102.443832] ignition[1640]: INFO     : GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: getsockopt: no route to host                                                                                                                                                                                                                                                                                                                      
[K[   [31m*[1;31m*[0m[31m*[0m] A start job is running for Ignition (files) (1min 39s / no limit)[  103.159325] ignition[1640]: INFO     : neither config drive nor metadata service were available in time. Continuing without a config...
[  103.166717] ignition[1640]: WARNING  : failed to fetch config: not a config (empty)                                                                                                                                                                                                                                                                                                                                                                                                     
[  103.172063] ignition[1640]: INFO     : not a config (empty): ignoring user-provided config               
[K[    [31m*[1;31m*[0m] [  103.202333] ignition[1640]: INFO     : reading system config file "/usr/lib/ignition/default.ign"
[  103.207857] ignition[1640]: INFO     : no config at "/usr/lib/ignition/default.ign"                                                                                                                                                                                                                                                                                                                                                                                                     
[  103.212918] ignition[1640]: ERROR    : files: timed out while fetching config from config drive (CONFIG-2)
A start job is running for Ignition (files) (1mi[  103.219450] ignition[1640]: ERROR    : files: timed out while fetching config from config drive (config-2)                                                                                                                                                                                                                                                                                                                              
n 40s / no limit)[  103.227552] ignition[1640]: INFO     : files: files passed                              
[K[[32m  OK  [0m[  103.234089] ignition[1640]: INFO     : Ignition finished successfully                                                                                                                                                                                                                                                                                                                                                                                                   
] Started Ignition[  103.238419] systemd[1]: Started Ignition (files).      


Version-Release number of the following components:
[openshift@dhcp-140-70 installer]$ bin/openshift-install version 
bin/openshift-install unreleased-master-540-g12af0c9b8e6a090c041b19c2fb0c040188607bcb

How reproducible:
Sometimes

Steps to Reproduce:
1. Try to setup OCP on OSP with installer
2. Check bootstrap or api boot log to make sure they are working well
3.

Actual results:
As description

Expected results:
Should work well and success to dial openstack metadata server

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

Comment 1 Flavio Percoco 2019-03-13 11:38:06 UTC
This has been fixed upstream: https://github.com/openshift/installer/pull/1390

Comment 2 weiwei jiang 2019-03-15 10:01:23 UTC
Unfortunately, I got bootstrap and api is working will this time, but masters got this isssue.

[openshift@dhcp-140-70 installer]$ bin/openshift-install version 
bin/openshift-install unreleased-master-560-g974d9b0848866f03d4dd8c577d8b7ef28756a1d5-dirty
built from commit 974d9b0848866f03d4dd8c577d8b7ef28756a1d5

[    3.590429] iscsid[467]: can't open InitiatorAlias configuration file /etc/iscsi/initiatorname.iscsi
[    3.598874] iscsid[467]: can't open iscsid.safe_logout configuration file /etc/iscsi/iscsid.conf
[    3.995768] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #4
[    4.000615] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    4.224919] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    5.596229] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #5
[    5.601071] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    8.796609] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #6
[    8.801560] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   11.453595] dhclient[1584]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 20 (xid=0x7e0ed866)
[   13.796972] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #7
[   13.802551] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   18.797357] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #8
[   18.802735] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   23.797705] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #9
[   23.802374] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   28.798044] ignition[481]: GET http://169.254.169.254/openstack/latest/user_data: attempt #10
[   28.802690] ignition[481]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   30.606979] dhclient[1584]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8 (xid=0x7e0ed866)
[   32.594697] ignition[481]: neither config drive nor metadata service were available in time. Continuing without a config...
[   32.600272] ignition[481]: failed to fetch config: not a config (empty)

Comment 3 weiwei jiang 2019-03-15 10:58:10 UTC
Checked again and met this for bootstrap and api this time

[openshift@dhcp-140-70 installer]$ bin/openshift-install version 
bin/openshift-install unreleased-master-560-g974d9b0848866f03d4dd8c577d8b7ef28756a1d5
built from commit 974d9b0848866f03d4dd8c577d8b7ef28756a1d5

(openstack) server list --name wjiang
+--------------------------------------+----------------------------+--------+-------------------------------------------------------+-------+----------------+                                                                                                                
| ID                                   | Name                       | Status | Networks                                              | Image | Flavor         |                                                                                                                
+--------------------------------------+----------------------------+--------+-------------------------------------------------------+-------+----------------+                                                                                                                
| 78cdfb63-cd5e-4fc2-8f0c-e14be3e6d91f | wjiang-ocp-fvkd5-master-1  | ACTIVE | wjiang-ocp-fvkd5-openshift=192.168.0.11               | rhcos | ci.m1.medlarge |                                                                                                                
| 984783ba-5303-4d35-a26a-fe7e9b784e3d | wjiang-ocp-fvkd5-master-2  | ACTIVE | wjiang-ocp-fvkd5-openshift=192.168.0.5                | rhcos | ci.m1.medlarge |                                                                                                                
| 0f4812e9-9f18-4336-b1c8-5a356a90a8e1 | wjiang-ocp-fvkd5-master-0  | ACTIVE | wjiang-ocp-fvkd5-openshift=192.168.0.9                | rhcos | ci.m1.medlarge |                                                                                                                
| e4347058-6889-4dc7-a5ad-d98115e468f4 | wjiang-ocp-fvkd5-api       | ACTIVE | wjiang-ocp-fvkd5-openshift=192.168.128.13, 10.0.77.71 | rhcos | ci.m1.medlarge |                                                                                                                
| bfb430a2-a6b7-4899-9117-6bb3bca7a181 | wjiang-ocp-fvkd5-bootstrap | ACTIVE | wjiang-ocp-fvkd5-openshift=192.168.0.10               | rhcos | ci.m1.medlarge |                                                                                                                
+--------------------------------------+----------------------------+--------+-------------------------------------------------------+-------+----------------+    


part of boot log of wjiang-ocp-fvkd5-bootstrap:

[    5.147991] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #4
[    5.154008] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    5.601541] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    6.748673] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #5
[    6.755664] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    9.840795] dhclient[1583]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6 (xid=0x7a39d5d2)
[    9.949077] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #6
[    9.955439] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   14.949788] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #7
[   14.957273] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   15.455825] dhclient[1583]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7 (xid=0x7a39d5d2)
[   19.950196] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #8
[   19.957614] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   22.451638] dhclient[1583]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 9 (xid=0x7a39d5d2)
[   24.950728] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #9
[   24.958736] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   29.951109] ignition[466]: GET http://169.254.169.254/openstack/latest/user_data: attempt #10
[   29.959172] ignition[466]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   31.595989] dhclient[1583]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 19 (xid=0x7a39d5d2)
[   33.745242] ignition[466]: neither config drive nor metadata service were available in time. Continuing without a config...
[   33.754528] ignition[466]: timed out while fetching config from config drive (config-2)
[[32m  OK  [0m] Started Ignition (disks).
[   33.762476] ignition[466]: timed out while fetching config from config drive (CONFIG-2)
[   33.768096] systemd[1]: Started Ignition (disks).
[   33.771753] ignition[466]: failed to fetch config: not a config (empty)
[   33.775737] ignition[466]: not a config (empty): ignoring user-provided config
[   33.781088] ignition[466]: reading system config file "/usr/lib/ignition/default.ign"
[   33.786469] ignition[466]: no config at "/usr/lib/ignition/default.ign"


also wjiang-ocp-fvkd5-api

[    4.018893] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #4
[    4.023585] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    4.216511] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    5.619149] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #5
[    5.623783] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[    8.819580] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #6
[    8.824254] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   10.700005] dhclient[1582]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 13 (xid=0x48a379fd)
[   13.819940] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #7
[   13.824619] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   18.820319] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #8
[   18.824988] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   23.676860] dhclient[1582]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 14 (xid=0x48a379fd)
[   23.820812] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #9
[   23.825591] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   28.821256] ignition[468]: GET http://169.254.169.254/openstack/latest/user_data: attempt #10
[   28.828608] ignition[468]: GET error: Get http://169.254.169.254/openstack/latest/user_data: dial tcp 169.254.169.254:80: connect: network is unreachable
[   32.611715] ignition[468]: neither config drive nor metadata service were available in time. Continuing without a config...
[   32.617872] ignition[468]: failed to fetch config: not a config (empty)
[[32m  OK  [0m] Started Ignition (disks).
[   32.622242] ignition[468]: not a config (empty): ignoring user-provided config
[   32.626316] systemd[1]: Started Ignition (disks).
[   32.628965] ignition[468]: reading system config file "/usr/lib/ignition/default.ign"
[   32.633212] ignition[468]: no config at "/usr/lib/ignition/default.ign"

Comment 7 Eric Duen 2019-07-30 15:40:30 UTC
Might be a transient issue with Upshift.  May also require a fix from CoreOS team to help mitigate time outs.

Comment 8 weiwei jiang 2019-08-01 06:49:30 UTC
Checked with 4.2.0-0.nightly-2019-07-31-162901 and also recent versions
and we do not meet this anymore recently.

Comment 9 Eric Duen 2019-08-06 12:23:37 UTC
Moving to ON_QA to since weiwei already verified.

Comment 10 weiwei jiang 2019-08-07 04:56:58 UTC
Move to verified, since it's more like a unstable upshift OpenStack issue.


Note You need to log in before you can comment on or make changes to this bug.