Bug 1382822

Summary: Anaconda boot option "nicdelay" fails due to ping bug
Product: Red Hat Enterprise Linux 6 Reporter: Blake Powers <bpowers>
Component: NetworkManagerAssignee: Thomas Haller <thaller>
Status: CLOSED WONTFIX QA Contact: Desktop QE <desktop-qa-list>
Severity: high Docs Contact:
Priority: high    
Version: 6.8CC: aloughla, atragler, bgalvani, bpowers, cww, fgiudici, lrintel, mleitner, mmatsuya, rkhan, sukulkar, thaller
Target Milestone: rcFlags: mleitner: needinfo? (bpowers)
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-08-15 20:07:17 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:
Attachments:
Description Flags
Kcikstart nicdelay Message none

Description Blake Powers 2016-10-07 20:13:04 UTC 
Created attachment 1208233 [details]
Kcikstart nicdelay Message

Description of problem:
Kickstart build requires manual intervention after not finding ks.cfg on http server on first pass.  Anaconda NetworkManager activates the eth0 device before its ready and thus the http server can't be reached on first pass. Anaconda boot option "nicdelay" is designed to help but fails due to what seems to be a bug in "ping" itself. 

For example: With nicdelay=30 anaconda issues the following test against the default gateway:
     ~~~
     # ping -I eth0 -c 1 -w 30 192.168.0.1
     ~~~
That 30 seconds actually turns out to be about 3 seconds due to the way "ping" performs with that command.  


Spanning tree or Portfast have been eliminated based on these two parameters: 

    1.  Applied the same test on an isolated network with all hosts on the same switch.

    2. That does not address the fact that nicdelay times out in 3 seconds not 30.  

How reproducible: Easily


Steps to Reproduce: 
1. Create a RHEL 6.8 .cfg file 
2. Append the kickstart to the kernel line 
3. Add the 'nicdelay' variable

Actual results:
Kickstart build requires manual intervention after not finding ks.cfg on http server on first pass.  Anaconda NetworkManager activates the eth0 device before its ready and thus the http server can't be reached on first pass.

Expected results:
The kickstart proceeds the first time it is entered without manual user intervention

Additional info:
The 'nicdelay' has been recently introduced in update packages of rhel 6.8
-------------------------------------------------------------------------------
anaconda-13.21.239-1.el6.x86_64.rpm
anaconda-debuginfo-13.21.239-1.el6.x86_64.rpm
------------------------------------------------------------------------------- 
Attempting alternate delay variables (10,20, 30) for nicdelay does not alter outcome. 
yum.log display: 
--------------------------------------------------------------------------------
[2016-10-04 21:17:40,857] DEBUG   : No package named netxen-firmware available to be installed
[2016-10-04 21:17:40,899] DEBUG   : No package named abrt-plugin-mailx available to be installed
[2016-10-04 21:17:40,913] DEBUG   : No package named openssl-ibmca available to be installed
[2016-10-04 21:17:40,914] DEBUG   : No package named abrt-plugin-sosreport available to be installed
[2016-10-04 21:17:40,951] DEBUG   : No package named redhat-access-insights available to be installed
-------------------------------------------------------------------------------- syslog denotes: 
--------------------------------------------------------------------------------
directives may interfer with your rsyslog.conf settings. We suggest upgrading your config and adding -c5 as the first rsyslogd option.
04:16:55,516 ERR rsyslogd:Warning: backward compatibility layer added to following directive to rsyslog.conf: ModLoad immark
04:16:55,516 ERR rsyslogd:Warning: backward compatibility layer added to following directive to rsyslog.conf: MarkMessagePeriod 1200
04:16:55,516 ERR rsyslogd:Warning: backward compatibility layer added to following directive to rsyslog.conf: ModLoad imuxsock----------------------------------------------------------------------------------------------
04:17:03,394 INFO NetworkManager: <debug> [1475641023.394148] [nm-manager.c:4798] get_permissions_done_cb(): Permissions request failed: Remote Exception invoking org.freedesktop.PolicyKit1.Authority.CheckAuthorization() on /org/freedesktop/PolicyKit1/Authority at name org.freedesktop.PolicyKit1: org.freedesktop.DBus.Error.Spawn.ExecFailed: Cannot launch daemon, file not found or permissions invalid
04:17:03,402 WARNING NetworkManager: <warn> error requesting auth for org.freedesktop.NetworkManager.enable-disable-network: (26) Remote Exception invoking org.freedesktop.PolicyKit1.Authority.CheckAuthorization() on /org/freedesktop/PolicyKit1/Authority at name org.freedesktop.PolicyKit1: org.freedesktop.DBus.Error.Spawn.ExecFailed: Cannot launch daemon, file not found or permissions invalid
04:17:03,402 WARNING NetworkManager: <warn> error requesting auth for org.freedesktop.NetworkManager.sleep-wake: (26) Remote Exception invoking org.freedesktop.PolicyKit1.Authority.CheckAuthorization() on /org/freedesktop/PolicyKit1/Authority at name org.freedesktop.PolicyKit1: org.freedesktop.DBus.Error.Spawn.ExecFailed: Cannot launch daemon, file not found or permissions invalid
....
04:17:04,426 INFO NetworkManager: <debug> [1475641024.426769] [nm-manager.c:1808] system_create_virtual_devices(): creating virtual devices...
--------------------------------------------------------------------------------Program logs display: 
--------------------------------------------------------------------------------
21:17:32,071 INFO    : Running... ['dmsetup', 'info', '--columns', '--noheadings', '-o', 'devno', '/dev/vda']
21:17:32,074 ERROR   : Device vda not found
21:17:32,074 ERROR   : Command failed
21:17:32,075 INFO    : Running... ['udevadm', 'settle', '--timeout=300']
21:17:32,091 INFO    : Running... ['dmsetup', 'info', '--columns', '--noheadings', '-o', 'devno', '/dev/vda']
21:17:32,094 ERROR   : Device vda not found
21:17:32,094 ERROR   : Command failed
21:17:32,095 INFO    : Running... ['udevadm', 'settle', '--timeout=300']
21:17:32,108 INFO    : Running... ['dmsetup', 'info', '--columns', '--noheadings', '-o', 'devno', '/dev/vda']
21:17:32,111 ERROR   : Device vda not found
21:17:32,111 ERROR   : Command failed
21:17:32,111 INFO    : Running... ['udevadm', 'settle', '--timeout=300']
21:17:32,133 INFO    : Running... ['udevadm', 'settle', '--timeout=300']
21:17:32,146 INFO    : Running... ['dmsetup', 'info', '--columns', '--noheadings', '-o', 'devno', '/dev/vda']
21:17:32,149 ERROR   : Device vda not found
21:17:32,149 ERROR   : Command failed
--------------------------------------------------------------------------------
The anaconda.log displays: 
-------------------------------------------------------------------------------
kernel command line: method=http://192.168.0.29/centos6U8_x86_64/ ks=http://192.168.0.29/centos6U8_x86_64/std_image/ks_files/rh6bootiso.ks.cfg ksdevice=eth0 ip=192.168.0.114 netmask=255.255.255.0 dns1=192.168.0.1 gateway=192.168.0.1 nicdelay=30 console=tty0
....
Error downloading http://192.168.0.29/centos6U8_x86_64/std_image/ks_files/rh6bootiso.ks.cfg: Couldn't connect to server
ERROR   : failed to retrieve http://192.168.0.29/centos6U8_x86_64/std_image/ks_files/rh6bootiso.ks.cfg
...
04:17:28,622 INFO    : transferring http://192.168.0.29/centos6U8_x86_64/images/install.img
04:17:28,775 INFO    : mounted loopback device /mnt/runtime on /dev/loop0 as /tmp/install.img
04:17:28,775 INFO    : got stage2 at url http://192.168.0.29/centos6U8_x86_64/images/install.img
04:17:28,806 INFO    : Loading SELinux policy
04:17:29,235 INFO    : getting ready to spawn shell now
-------------------------------------------------------------------------------
method= is deprecated and it is now suggested to use repo=
linksleep is also a new veriable that has been introduced.