Bug 201772

Summary: dhcp takes a long time during FC6T2 install (IPv6 issue?)
Product: [Fedora] Fedora Reporter: Orion Poplawski <orion>
Component: anacondaAssignee: David Cantrell <dcantrell>
Status: CLOSED NOTABUG QA Contact: Mike McLean <mikem>
Severity: medium Docs Contact:
Priority: medium    
Version: 6   
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2006-08-08 20:13:08 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Full anaconda log none

Description Orion Poplawski 2006-08-08 19:43:00 UTC
Description of problem:

During PXE/kickstart install, the dhcp request for eth0 took a long time. 
Relevent entries in the anaconda.log are:

10:13:12 INFO    : sending dhcp request through device eth0
10:13:12 DEBUG   : waiting for link eth0...
10:13:12 DEBUG   :    0 seconds.
10:13:12 INFO    : DHCP eth0  - bringing link UP - 1002 0
10:13:12 INFO    : Listening on LPF/eth0/00:c0:4f:1b:fb:61
10:13:12 INFO    : Sending on   LPF/eth0/00:c0:4f:1b:fb:61
10:13:12 INFO    : Sending on   Socket/fallback
10:13:12 INFO    : DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
10:13:12 INFO    : DHCPOFFER from 192.168.0.8
10:13:12 INFO    : DHCPREQUEST on eth0 to 255.255.255.255 port 67
10:13:12 INFO    : DHCPACK from 192.168.0.8
10:13:12 INFO    : bound to 192.168.0.80 -- renewal in 6528 seconds.
10:13:12 INFO    : DHCPv6: NIC: 0x8d51530 eth0 0x8d518f0
10:13:12 INFO    : setup interface
10:13:12 DEBUG   : gethwid: ioctl SIOCGIFHWADDR
10:13:12 DEBUG   : found an interface eth0 harware 00:ffffffc0:4f:1b:fffffffb:61
10:13:12 DEBUG   : generated a new DUID: 00:01:00:01:0c:6b:20:38:00:c0:4f:1b:fb:61
10:13:12 INFO    : link local addr is fe80::2c0:4fff:fe1b:fb61
10:13:12 INFO    : inbound addr is fe80::2c0:4fff:fe1b:fb61%eth0/28
10:13:14 INFO    : outbound addr is fe80::2c0:4fff:fe1b:fb61%eth0/28
10:13:14 DEBUG   : gethwid: ioctl SIOCGIFHWADDR
10:13:14 INFO    : dhcpv6 doesn't support hardware type 776
10:13:14 INFO    : doesn't support sit0 address family 0
10:13:14 DEBUG   : gethwid: ioctl SIOCGIFHWADDR
10:13:14 DEBUG   : found an interface eth0 harware 00:ffffffc0:4f:1b:fffffffb:61
10:13:14 DEBUG   :  create iaid 458211328 for interface eth0
10:13:14 DEBUG   : gethwid: ioctl SIOCGIFHWADDR
10:13:14 DEBUG   : found an interface eth0 harware 00:ffffffc0:4f:1b:fffffffb:61
10:13:14 DEBUG   :  create iaid 458211328 for interface eth0
10:13:14 DEBUG   : gethwid: ioctl SIOCGIFHWADDR
10:13:14 DEBUG   : found an interface eth0 harware 00:ffffffc0:4f:1b:fffffffb:61
10:13:14 DEBUG   :  found interface eth0 iaid 458211328
10:13:14 DEBUG   : interface eth0 iaid is 458211328
10:13:14 DEBUG   : open_netlink_socket called
10:13:14 DEBUG   : netlink_send_rtmsg called
10:13:14 DEBUG   : netlink_recv_rtgenmsg called
10:13:14 DEBUG   : netlink_send_rtgenmsg called
10:13:14 DEBUG   : netlink_recv_rtgenmsg called
10:13:14 DEBUG   : create an event 0x8d51038 xid 0 for state 0
10:13:14 DEBUG   : reset a timer on eth0, state=INIT, timeo=0, retrans=569
10:13:14 DEBUG   :

entering select - client state: 0 UNKNOWN timeout: 0x82918c8 0 568934

10:13:15 INFO    : libdhcp_check
10:13:15 DEBUG   : client6_timo - DHCP6_INIT
10:13:15 DEBUG   : client6_timo - DHCP6_SOLICIT
10:13:15 DEBUG   : client6_timo - DHCP6_INFOREQ
10:13:15 DEBUG   : client6_timo - DHCP6_REQUEST
10:13:15 DEBUG   : send state SOLICIT
10:13:15 DEBUG   : ifp 0x8d337a8 event 0x8d51038 a new XID (2f8f54) is generated
10:13:15 DEBUG   : set client ID
10:13:15 DEBUG   : set opt_8
10:13:15 DEBUG   : set opt_28
10:13:15 DEBUG   : set IA_NA iaidinfo: iaid 458211328 renewtime 0 rebindtime 0
10:13:15 DEBUG   : set opt_3
10:13:15 DEBUG   : send dst if eth0 addr is ff02::1:2%eth0 scope id is 3
10:13:15 DEBUG   : send solicit to ff02::1:2%eth0
10:13:15 DEBUG   : DUID is 00:01:00:01:0c:6b:20:38:00:c0:4f:1b:fb:61, DUID_LEN is 14
10:13:15 DEBUG   : removing ID (ID: 00:01:00:01:0c:6b:20:38:00:c0:4f:1b:fb:61)
10:13:15 DEBUG   : DUID is , DUID_LEN is 0
10:13:15 DEBUG   : reset a timer on eth0, state=SOLICIT, timeo=0, retrans=1010
10:13:15 DEBUG   :

entering select - client state: 0 UNKNOWN timeout: 0x82918c8 1 11433

10:13:16 INFO    : libdhcp_check
10:13:16 DEBUG   : client6_timo - DHCP6_SOLICIT
10:13:16 DEBUG   : client6_timo - DHCP6_INFOREQ
10:13:16 DEBUG   : client6_timo - DHCP6_REQUEST
10:13:16 DEBUG   : send state SOLICIT
10:13:16 DEBUG   : set client ID
10:13:16 DEBUG   : set opt_8
10:13:16 DEBUG   : set opt_28
10:13:16 DEBUG   : set IA_NA iaidinfo: iaid 458211328 renewtime 0 rebindtime 0
10:13:16 DEBUG   : set opt_3
10:13:16 DEBUG   : send dst if eth0 addr is ff02::1:2%eth0 scope id is 3
10:13:16 DEBUG   : send solicit to ff02::1:2%eth0
10:13:16 DEBUG   : DUID is 00:01:00:01:0c:6b:20:38:00:c0:4f:1b:fb:61, DUID_LEN is 14
10:13:16 DEBUG   : removing ID (ID: 00:01:00:01:0c:6b:20:38:00:c0:4f:1b:fb:61)
10:13:16 DEBUG   : DUID is , DUID_LEN is 0
10:13:16 DEBUG   : reset a timer on eth0, state=SOLICIT, timeo=1, retrans=2046
10:13:16 DEBUG   :

entering select - client state: 0 UNKNOWN timeout: 0x82918c8 2 47259

...  this repeats until:

10:14:48 INFO    : libdhcp_check
10:14:48 INFO    : DHCPv6 eth0 - state: DHC_TIMEDOUT
10:14:48 ERROR   : DHCPv6 eth0 - TIMED OUT - failure.
10:14:49 INFO    : DHCPv4 eth0 - obtained lease 192.168.0.80
10:14:49 INFO    : DHCPv4 eth0 - option subnet-mask: 255.255.255.0
10:14:49 INFO    : DHCPv4 eth0 - option subnet-mask - prefix_len: 24 broadcast:
192.168.0
.255
10:14:49 INFO    : DHCPv4 eth0 - option routers:
10:14:49 INFO    : doing kickstart... setting it up
10:14:50 INFO    : DHCPv4 interface configuration succeeded.
10:14:50 DEBUG   : waiting for link eth0...
10:14:50 DEBUG   :    0 seconds.
10:14:50 INFO    : starting to STEP_URL

Comment 1 Orion Poplawski 2006-08-08 19:43:00 UTC
Created attachment 133825 [details]
Full anaconda log

Comment 2 David Cantrell 2006-08-08 20:13:08 UTC
Uncheck IPv6 support unless you have an IPv6 DHCP server.  For the FC6 test
releases, we are leaving IPv4 and IPv6 selected by default so we can uncover any
problems with leaving both selected (aside from timeouts).

The IPv6 DHCP request will time out after 45 seconds, per the RFC.  There are
other networking tasks wrapped on the ends of the request that add a little to
the 45 second timeout.

What you are seeing is normal.  If it crashed, that would be another thing.

Thanks.