Bug 460989 - ntpd and NetworkManager have a sync problem
Summary: ntpd and NetworkManager have a sync problem
Keywords:
Status: CLOSED DUPLICATE of bug 456743
Alias: None
Product: Fedora
Classification: Fedora
Component: ntp
Version: 9
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Miroslav Lichvar
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-09-03 06:55 UTC by dilu
Modified: 2008-09-04 08:14 UTC (History)
0 users

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2008-09-04 08:14:33 UTC
Type: ---


Attachments (Terms of Use)

Description dilu 2008-09-03 06:55:44 UTC
Description of problem:
When NetworkManager and ntp service are both switched on to start in runlevel 3
ntpd starts before the NetworkManager has finished all stages and the network is up and running. So ntpd can't connect to its time servers.
The line NETWORKWAIT=yes in /etc/sysconfig/network fixes this problem.

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


How reproducible:


Steps to Reproduce:
1. chkconfig NetworkManager on
2. chkconfig ntpd on
3. reboot
  
Actual results:
# cat /var/log/messages
...
Sep 2 12:52:36 kapok NetworkManager: <info> starting...
Sep 2 12:52:36 kapok NetworkManager: <info> eth0: Device is fully-supported using driver 'pegasus'.
Sep 2 12:52:36 kapok NetworkManager: <info> Found new Ethernet device 'eth0'.
Sep 2 12:52:36 kapok NetworkManager: <info> (eth0): exported as /org/freedesktop/Hal/devices/net_00_50_ba_76_66_f1
Sep 2 12:52:36 kapok NetworkManager: <info> Trying to start the supplicant...
Sep 2 12:52:36 kapok NetworkManager: <info> Trying to start the system settings daemon...
Sep 2 12:52:37 kapok nm-system-settings: Loaded plugin ifcfg-fedora: (c) 2007 - 2008 Red Hat, Inc. To report bugs please use the NetworkManager mailing list.
Sep 2 12:52:37 kapok nm-system-settings: ifcfg-fedora: parsing /etc/sysconfig/network-scripts/ifcfg-lo ...
Sep 2 12:52:37 kapok nm-system-settings: ifcfg-fedora: error: Ignoring loopback device config.
Sep 2 12:52:37 kapok nm-system-settings: ifcfg-fedora: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ...
Sep 2 12:52:37 kapok nm-system-settings: ifcfg-fedora: read connection 'System eth0'
Sep 2 12:52:38 kapok kernel: NET: Registered protocol family 10
Sep 2 12:52:38 kapok kernel: lo: Disabled Privacy Extensions
Sep 2 12:52:39 kapok ntpd[1272]: ntpd 4.2.4p4@1.1520-o Mon Apr 7 17:39:41 UTC 2008 (1)
Sep 2 12:52:39 kapok ntpd[1273]: precision = 3.000 usec
Sep 2 12:52:39 kapok ntpd[1273]: Listening on interface #0 wildcard, 0.0.0.0#123 Disabled
Sep 2 12:52:39 kapok ntpd[1273]: Listening on interface #1 wildcard, ::#123 Disabled
Sep 2 12:52:39 kapok ntpd[1273]: Listening on interface #2 lo, ::1#123 Enabled
Sep 2 12:52:39 kapok ntpd[1273]: Listening on interface #3 lo, 127.0.0.1#123 Enabled
Sep 2 12:52:39 kapok ntpd[1273]: kernel time sync status 0040
Sep 2 12:52:39 kapok ntpd[1273]: frequency initialized 0.000 PPM from /var/lib/ntp/drift
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): device state change: 1 -> 2
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): bringing up device.
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): preparing device.
Sep 2 12:52:40 kapok kernel: eth0: set allmulti
Sep 2 12:52:40 kapok kernel: eth0: set allmulti
Sep 2 12:52:40 kapok kernel: eth0: set allmulti
Sep 2 12:52:40 kapok kernel: eth0: set allmulti
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): deactivating device.
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): carrier now ON (device state 2)
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): device state change: 2 -> 3
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) starting connection 'System eth0'
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): device state change: 3 -> 4
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): device state change: 4 -> 5
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep 2 12:52:40 kapok NetworkManager: <info> (eth0): device state change: 5 -> 7
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Sep 2 12:52:40 kapok NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Sep 2 12:52:41 kapok ntpd[1273]: Cannot find existing interface for address 81.169.180.26
Sep 2 12:52:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:52:41 kapok ntpd[1273]: Cannot find existing interface for address 88.198.177.94
Sep 2 12:52:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:52:41 kapok ntpd[1273]: Cannot find existing interface for address 85.214.29.92
Sep 2 12:52:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:52:41 kapok ntpd[1273]: Cannot find existing interface for address 217.172.188.162
Sep 2 12:52:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:52:41 kapok NetworkManager: <info> (eth0): device state change: 7 -> 8
Sep 2 12:52:42 kapok NetworkManager: <info> Policy set (eth0) as default device for routing and DNS.
Sep 2 12:52:42 kapok NetworkManager: <info> Activation (eth0) successful, device activated.
Sep 2 12:52:42 kapok NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 2 12:53:41 kapok ntpd[1273]: Cannot find existing interface for address 81.169.180.26
Sep 2 12:53:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:53:41 kapok ntpd[1273]: Cannot find existing interface for address 88.198.177.94
Sep 2 12:53:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:53:41 kapok ntpd[1273]: Cannot find existing interface for address 85.214.29.92
Sep 2 12:53:41 kapok ntpd_initres[1279]: ntpd indicates no data available!
Sep 2 12:53:41 kapok ntpd[1273]: Cannot find existing interface for address 217.172.188.162
Sep 2 12:53:41 kapok ntpd_initres[1279]: ntpd indicates no data available!



Expected results: (NETWORKWAIT=yes)
# cat /var/log/messages
...
Sep  3 09:37:47 kapok NetworkManager: <info>  starting...
Sep  3 09:37:48 kapok NetworkManager: <info>  eth0: Device is fully-supported using driver 'pegasus'.
Sep  3 09:37:48 kapok NetworkManager: <info>  Found new Ethernet device 'eth0'.
Sep  3 09:37:48 kapok NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_50_ba_76_66_f1
Sep  3 09:37:48 kapok NetworkManager: <info>  Trying to start the supplicant...
Sep  3 09:37:48 kapok NetworkManager: <info>  Trying to start the system settings daemon...
Sep  3 09:37:48 kapok nm-system-settings: Loaded plugin ifcfg-fedora: (c) 2007 - 2008 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Sep  3 09:37:49 kapok nm-system-settings:    ifcfg-fedora: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... 
Sep  3 09:37:49 kapok nm-system-settings:    ifcfg-fedora:     error: Ignoring loopback device config.
Sep  3 09:37:49 kapok nm-system-settings:    ifcfg-fedora: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ... 
Sep  3 09:37:49 kapok nm-system-settings:    ifcfg-fedora:     read connection 'System eth0'
Sep  3 09:37:52 kapok NetworkManager: <info>  (eth0): device state change: 1 -> 2
Sep  3 09:37:52 kapok NetworkManager: <info>  (eth0): bringing up device.
Sep  3 09:37:52 kapok kernel: eth0: set allmulti
Sep  3 09:37:52 kapok kernel: eth0: set allmulti
Sep  3 09:37:52 kapok NetworkManager: <info>  (eth0): preparing device.
Sep  3 09:37:52 kapok NetworkManager: <info>  (eth0): deactivating device.
Sep  3 09:38:00 kapok kernel: NET: Registered protocol family 10
Sep  3 09:38:00 kapok kernel: lo: Disabled Privacy Extensions
Sep  3 09:38:00 kapok kernel: eth0: set allmulti
Sep  3 09:38:00 kapok kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep  3 09:38:01 kapok ntpd[1211]: ntpd 4.2.4p4@1.1520-o Mon Jul 28 11:12:44 UTC 2008 (1)
Sep  3 09:38:01 kapok ntpd[1212]: precision = 9.219 usec
Sep  3 09:38:01 kapok ntpd[1212]: Listening on interface #0 wildcard, 0.0.0.0#123 Disabled
Sep  3 09:38:01 kapok ntpd[1212]: Listening on interface #1 wildcard, ::#123 Disabled
Sep  3 09:38:01 kapok ntpd[1212]: Listening on interface #2 lo, ::1#123 Enabled
Sep  3 09:38:01 kapok ntpd[1212]: Listening on interface #3 lo, 127.0.0.1#123 Enabled
Sep  3 09:38:01 kapok ntpd[1212]: kernel time sync status 0040
Sep  3 09:38:01 kapok ntpd[1212]: frequency initialized -53.824 PPM from /var/lib/ntp/drift
Sep  3 09:39:59 kapok init: tty1 main process ended, respawning
Sep  3 10:28:38 kapok NetworkManager: <info>  (eth0): carrier now ON (device state 2)
Sep  3 10:28:38 kapok NetworkManager: <info>  (eth0): device state change: 2 -> 3
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) starting connection 'System eth0'
Sep  3 10:28:38 kapok NetworkManager: <info>  (eth0): device state change: 3 -> 4
Sep  3 10:28:38 kapok kernel: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep  3 10:28:38 kapok kernel: eth0: set allmulti
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Sep  3 10:28:38 kapok NetworkManager: <info>  (eth0): device state change: 4 -> 5
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Sep  3 10:28:38 kapok NetworkManager: <info>  (eth0): device state change: 5 -> 7
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Sep  3 10:28:38 kapok NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Sep  3 10:28:39 kapok NetworkManager: <info>  (eth0): device state change: 7 -> 8
Sep  3 10:28:40 kapok NetworkManager: <info>  Policy set (eth0) as default device for routing and DNS.
Sep  3 10:28:40 kapok NetworkManager: <info>  Activation (eth0) successful, device activated.
Sep  3 10:28:40 kapok NetworkManager: <info>  Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.


Additional info:
The hardware is an old Pentium MMX (Tillamook) Notebook with 266 MHz and 192 MB memory with an attached USB-Fast-Ethernet 100Mb/s (pegasus) adapter.

Comment 1 Miroslav Lichvar 2008-09-03 10:00:25 UTC
ntpd should work correctly even when started before network interfaces are ready.

Do the servers listed in ntp.conf have dynamic keyword specified? Is there a local DNS server running?

Comment 2 dilu 2008-09-03 12:23:01 UTC
Yes, the servers have dynamic keywords specified (thats the default in Fedora 9).
A local DNS server is not running.

Comment 3 Miroslav Lichvar 2008-09-03 12:56:47 UTC
That's weird, the error messages about finding existing interface should be emitted only for servers without dynamic keyword.

Can you please verify that the latest ntp (4.2.4p4-7) from updates is installed? In the first half of the log you posted is output of ntp-4.2.4p4-6 which had a bug related to name resolving.

Also, what does "ntpq -pn" executed at least 15 minutes after boot print?

Comment 4 dilu 2008-09-04 07:56:05 UTC
OK, there was the old version of ntpd installed.
After update everything seems ok now.
No more error messages.

Comment 5 Miroslav Lichvar 2008-09-04 08:14:33 UTC
Thanks, closing as duplicate.

*** This bug has been marked as a duplicate of bug 456743 ***


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