View Issue Details

IDProjectCategoryView StatusLast Update
0014716CentOS-7ntppublic2019-01-23 18:04
Reporteroguzhan 
PrioritynormalSeverityminorReproducibilitysometimes
Status newResolutionopen 
Platformx86_64OSCentOSOS Version7.4
Product Version7.4.1708 
Target VersionFixed in Version 
Summary0014716: ntpd.service starts too soon in the boot process (before network) and fails to recover when network comes up
DescriptionThe default ntpd.service defines the unit dependency as:

After=syslog.target ntpdate.service sntp.service

This means that it can be started before NetworkManager starts up. When this happens, it's not able to resolve the server entries in /etc/ntp.conf and gets stuck in a bad state until it is restarted manually.


Steps To Reproducesystemctl disable chronyd
yum install ntp
Modify /etc/ntp.conf and add some servers if it's not already present
systemctl enable ntpd
reboot
systemctl status ntpd
  will show it as active, with two running processes but with the permission denied messages (these might take a couple of minutes after boot to show up)
ntpq -c peers will return
No association ID's returned

Additional InformationDuring boot:

Apr 24 17:16:06 myhost kernel: Kernel command line: BOOT_IMAGE=/vmlinuz-3.10.0-693.11.6.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=en_US.UTF-8
....
Apr 24 17:16:09 myhost ntpd[713]: ntpd 4.2.6p5@1.2349-o Wed Apr 12 21:24:06 UTC 2017 (1)
Apr 24 17:16:09 myhost ntpd[762]: proto: precision = 0.050 usec
Apr 24 17:16:09 myhost ntpd[762]: 0.0.0.0 c01d 0d kern kernel time sync enabled
Apr 24 17:16:09 myhost ntpd[762]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Apr 24 17:16:09 myhost ntpd[762]: Listen and drop on 1 v6wildcard :: UDP 123
Apr 24 17:16:09 myhost ntpd[762]: Listen normally on 2 lo 127.0.0.1 UDP 123
Apr 24 17:16:09 myhost ntpd[762]: Listening on routing socket on fd #19 for interface updates
Apr 24 17:16:09 myhost ntpd[762]: Deferring DNS for myntpserver1 1
Apr 24 17:16:09 myhost ntpd[762]: Deferring DNS for myntpserver2 1
Apr 24 17:16:09 myhost ntpd[762]: Deferring DNS for myntpserver3 1
Apr 24 17:16:09 myhost ntpd[762]: 0.0.0.0 c016 06 restart
Apr 24 17:16:09 myhost ntpd[762]: 0.0.0.0 c012 02 freq_set kernel 0.000 PPM
Apr 24 17:16:09 myhost ntpd[762]: 0.0.0.0 c011 01 freq_not_set
...
Apr 24 17:16:09 myhost systemd: Started Network Manager.
Apr 24 17:16:09 myhost systemd: Starting Network Manager Wait Online...
Apr 24 17:16:09 myhost dbus-daemon: dbus[739]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr 24 17:16:09 myhost dbus[739]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr 24 17:16:09 myhost systemd: Starting Network Manager Script Dispatcher Service...
Apr 24 17:16:09 myhost dbus[739]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 24 17:16:09 myhost dbus-daemon: dbus[739]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 24 17:16:09 myhost systemd: Started Network Manager Script Dispatcher Service.
....
Apr 24 17:16:11 myhost ntpd_intres[780]: DNS myntpserver1-> 10.0.0.1
Apr 24 17:16:11 myhost ntpd_intres[780]: ntp_intres.request: permission denied
Apr 24 17:16:11 myhost ntpd_intres[780]: DNS myntpserver2 -> 10.0.0.2
Apr 24 17:16:11 myhost ntpd_intres[780]: ntp_intres.request: permission denied
Apr 24 17:16:11 myhost ntpd_intres[780]: DNS myntpserver3 > 10.0.0.3
Apr 24 17:16:11 myhost ntpd_intres[780]: ntp_intres.request: permission denied

The permission denied message repeats every minute. There are also two ntpd processes.

 systemctl status ntpd
● ntpd.service - Network Time Service
   Loaded: loaded (/usr/lib/systemd/system/ntpd.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2018-04-25 14:35:22 CDT; 2min 17s ago
  Process: 21127 ExecStart=/usr/sbin/ntpd -u ntp:ntp $OPTIONS (code=exited, status=0/SUCCESS)
 Main PID: 21128 (ntpd)
   CGroup: /system.slice/ntpd.service
           ├─21128 /usr/sbin/ntpd -u ntp:ntp -g
           └─21129 /usr/sbin/ntpd -u ntp:ntp -g

Restarting ntpd fixes the problem. I can also replicate the end result by:

1. Stopping ntpd
2. Commenting out nameservers in /etc/resolv.conf
3. Starting ntpd
4. Notice that it's deferring name resolution and fires a second process.
5. Uncomment the nameservers in /etc/resolv.conf
6. Notice that ntpd now resolves the server names, but gets the permission denied message and ntpq -c peers returns "No association ID's returned"

Adding After = network.target to /usr/lib/systemd/system/ntpd.service and systemctl daemon-reload and rebooting seems to fix the problem.
TagsNo tags attached.
abrt_hash
URL

Activities

javelin

javelin

2019-01-23 18:04

reporter   ~0033664

It appears I had the same issue and my fix was the following:

vi /usr/lib/systemd/system/ntpd.service

from:
After=syslog.target ntpdate.service sntp.service

to:
After=NetworkManager-wait-online.service syslog.target ntpdate.service sntp.service

then,
init 6

Thanks for your post, I read it but I missed to read the last entry for the solution, but you gave me an idea where to look
and what could be causing the issue; eg, race condition.

Issue History

Date Modified Username Field Change
2018-04-25 19:45 oguzhan New Issue
2019-01-23 18:04 javelin Note Added: 0033664