Bug 859210 - NetworkManager takes too long to bring up interface during boot
NetworkManager takes too long to bring up interface during boot
Status: CLOSED WONTFIX
Product: Fedora
Classification: Fedora
Component: NetworkManager (Show other bugs)
16
x86_64 Linux
unspecified Severity high
: ---
: ---
Assigned To: Dan Williams
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-09-20 15:43 EDT by Ray Mikkelson
Modified: 2013-02-13 08:56 EST (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 911301 (view as bug list)
Environment:
Last Closed: 2013-02-13 08:56:57 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
/var/log/messages for 3 separate boot sequences (46.92 KB, application/octet-stream)
2012-09-20 15:43 EDT, Ray Mikkelson
no flags Details

  None (edit)
Description Ray Mikkelson 2012-09-20 15:43:40 EDT
Created attachment 615086 [details]
/var/log/messages for 3 separate boot sequences

Description of problem:

NetworkManager takes too long to bring up interface during boot which causes ypbind to fail, which causes cron to not work for non-root (i.e. NIS-served) users, which causes....

On my Dell Optiplex 390 with a Intel i5 2400 CPU with Intel H61 Express Chipset, it takes between 34s and 36s for the p4p1 interface activation to complete during the boot process.  This causes ypbind to fail upon boot, which causes a host of other problems.

I also get the following error messages (twice during the boot):

Sep 19 16:20:45 myserver NetworkManager[890]: <warn> failed to allocate link cache: (-12) Netlink Error (errno = Operation not supported)
Sep 19 16:20:45 myserver NetworkManager[890]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...

And it seems that NM fails to see the first couple of DHCPREQUEST responses because it sends multiple requests (I think that this is what consumes most of the time for NM to start):

Sep 19 17:13:34 myserver dhclient[925]: DHCPREQUEST on p4p1 to 255.255.255.255 port 67
Sep 19 17:13:42 myserver dhclient[925]: DHCPREQUEST on p4p1 to 255.255.255.255 port 67
Sep 19 17:14:04 myserver dhclient[925]: DHCPREQUEST on p4p1 to 255.255.255.255 port 67






Version-Release number of selected component (if applicable):

NetworkManager.x86_64                   1:0.9.4-6.git20120521.fc16   @updates   


How reproducible:

The time interval varies, but it's always > 30s.


Steps to Reproduce:
1. boot the server
2.
3.
  


Expected results:

Since it only takes NM 2s to send out the first DHCPREQUEST message, I would think that it should only take 3 or 4s for NM to start.


Additional info:

I'll attach an edited (to focus on the NM messages) /var/log/messages file for 3 different boot sequences.  They take between 34s and 40s for NM to activate.  The 3rd sequence has ypbind waiting for the NetworkManager-wait-online service, so ypbind actually starts cleanly on the last boot.
Comment 1 Ray Mikkelson 2012-09-20 16:19:18 EDT
Just thought to look at the logs of my DHCP server.  I think that the problem might actually be that the first couple of DHCPREQUEST messages may never go out on the wire (sent to the DHCP server).  Here's what my DHCP server sees:


Sep 19 17:14:41 dhcpserver dhcpd: DHCPDISCOVER from d0:67:e5:1c:95:09 via eth0
Sep 19 17:14:41 dhcpserver dhcpd: DHCPOFFER on 192.168.1.164 to d0:67:e5:1c:95:09 via eth0
Sep 19 17:14:41 dhcpserver dhcpd: DHCPREQUEST for 192.168.1.164 (192.168.1.12) from d0:67:e5:1c:95:09 via eth0
Sep 19 17:14:41 dhcpserver dhcpd: DHCPACK on 192.168.1.164 to d0:67:e5:1c:95:09 via eth0


I don't know why the times are skewed between the 2 boxes.  I run NTP (my DHCP server also happens to be my NTP server as well) on both boxes, and right now, they are within 1s of each other.  Maybe Fedora is not updating the HW clock when it shuts down??

I just checked, the HW clock is 38s slow on the client.  So the dhcpserver's timestamp of Sep 19 17:14:41 is roughly the same time as Sep 19 17:14:03 on the client box.  That would match up with the last DHCPREQUEST message of:

Sep 19 17:14:04 myserver dhclient[925]: DHCPREQUEST on p4p1 to 255.255.255.255 port 67
Comment 2 Fedora End Of Life 2013-01-16 08:14:40 EST
This message is a reminder that Fedora 16 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 16. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '16'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 16's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 16 is end of life. If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora, you are encouraged to click on 
"Clone This Bug" and open it against that version of Fedora.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 3 Fedora End Of Life 2013-02-13 08:56:59 EST
Fedora 16 changed to end-of-life (EOL) status on 2013-02-12. Fedora 16 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.

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