Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
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: NEW
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Installer
Version: 4.1
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: 4.2.0
Assignee: Flavio Percoco
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-04-11 07:02 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:
Target Upstream Version:


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"


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