Bug 814946 - systemd starts ntpdate after ntpd
Summary: systemd starts ntpdate after ntpd
Keywords:
Status: CLOSED DUPLICATE of bug 753586
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 16
Hardware: Unspecified
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-04-21 14:11 UTC by Ian Dall
Modified: 2012-04-25 07:12 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-04-25 07:12:55 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
The output of cat /proc/cmdline (237 bytes, application/octet-stream)
2012-04-21 14:11 UTC, Ian Dall
no flags Details
Output of dmesg (121.86 KB, text/plain)
2012-04-21 14:13 UTC, Ian Dall
no flags Details
grep ntp /var/log/messages (1.66 KB, text/plain)
2012-04-21 14:14 UTC, Ian Dall
no flags Details
Output from "systemd dump" (588.90 KB, text/plain)
2012-04-21 14:15 UTC, Ian Dall
no flags Details
Output from systemd --test (618.72 KB, text/plain)
2012-04-21 14:16 UTC, Ian Dall
no flags Details
Local /etc/systemd/system/ntpd.service (101 bytes, application/octet-stream)
2012-04-21 14:23 UTC, Ian Dall
no flags Details
dmesg ouput with increase log_buf_len (189.13 KB, text/plain)
2012-04-25 02:48 UTC, Ian Dall
no flags Details

Description Ian Dall 2012-04-21 14:11:53 UTC
Created attachment 579183 [details]
The output of cat /proc/cmdline

Description of problem:
I find that time is not synchronised (especially on a reboot after daylight saving change) due to ntpdate failing.

Version-Release number of selected component (if applicable):
ntpdate-4.2.6p4-1.fc16.i686

How reproducible:
Always

Steps to Reproduce:
1.grep /var/log/messages for ntpdate
2.
3.
  
Actual results:
ntpdate[nnn]: the NTP socket is in use, exiting

Expected results:
ntpdate should run successfully

Additional info:
I booted with systemd.log_level=debug and saved the output of dmesg (attached).
ntpd is clearly being started before ntpdate but I can't see why.

If I manually stop ntpd.service, start ntpdate.service and start ntpd.service things work as expected. As this seems to be a problem with the systemctl configuration I have attached the appropriate files.

Comment 1 Ian Dall 2012-04-21 14:13:11 UTC
Created attachment 579184 [details]
Output of dmesg

Comment 2 Ian Dall 2012-04-21 14:14:08 UTC
Created attachment 579185 [details]
grep ntp /var/log/messages

Comment 3 Ian Dall 2012-04-21 14:15:19 UTC
Created attachment 579186 [details]
Output from "systemd dump"

Comment 4 Ian Dall 2012-04-21 14:16:39 UTC
Created attachment 579187 [details]
Output from systemd --test

Comment 5 Ian Dall 2012-04-21 14:23:33 UTC
Created attachment 579188 [details]
Local /etc/systemd/system/ntpd.service

There is a local modification to ntpd.service (attached) which serves to ensure that ntpd doesn't start until the network is up, even if ntpdate has been disabled.

I can't see how this could cause a problem, but it is attached just in case.

Comment 6 Michal Schmidt 2012-04-23 09:25:09 UTC
ntpd.service and ntpdate.service are both owned by the "ntp" source package. If there exists and ordering requirement, it should be expressed in the unit file. Reassigning.

Comment 7 Michal Schmidt 2012-04-23 09:25:57 UTC
s/and ordering requirement/an ordering requirement/

Comment 8 Ian Dall 2012-04-23 22:31:36 UTC
(In reply to comment #6)
> ntpd.service and ntpdate.service are both owned by the "ntp" source package. If
> there exists and ordering requirement, it should be expressed in the unit file.
> Reassigning.

Except that, as far as I can see, the unit files for ntpd and ntpdate already have the ordering relationship. ntpd.service has:

After=syslog.target ntpdate.service


It just doesn't seem to take effect.

Comment 9 Michal Schmidt 2012-04-24 12:46:54 UTC
hm, I see.
I wonder what causes the following jobs to be enqueued:

[   40.786960] systemd[1]: Trying to enqueue job systemd-update-utmp-runlevel.service/start/ignore-requirements
[   40.787212] systemd[1]: Trying to enqueue job multi-user.target/start/ignore-requirements
[   40.787272] systemd[1]: Trying to enqueue job getty/start/ignore-requirements
[   40.787551] systemd[1]: Trying to enqueue job getty.target/start/ignore-requirements
[   40.787799] systemd[1]: Trying to enqueue job ntpdate.service/start/ignore-requirements
[   41.641098] systemd[1]: Trying to enqueue job systemd-update-utmp-runlevel.service/start/ignore-requirements
[   41.641137] systemd[1]: Trying to enqueue job multi-user.target/start/ignore-requirements
[   41.641401] systemd[1]: Trying to enqueue job ntpdate.service/start/ignore-requirements

It could come from unit deserialization, but I see no indication in the log of that happening.

In case we're missing some log items... Could you please boot with:
  systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M
and attach the new output of dmesg. Thanks.

Comment 10 Ian Dall 2012-04-25 02:48:36 UTC
Created attachment 580044 [details]
dmesg ouput with increase log_buf_len

OK. Here is the new dmesg output corresponding to the /proc/cmdline:

root=nfs:fs.beware.dropbear.id.au:/export/NFSroots/Fedora16 initrd=/images/Fedora16/initramfs-3.1.6-1.fc16.i686.img selinux=0 systemd.unit=multi-user.target systemd.log_level=debug systemd.log_level=debug systemd.log_target=kmsg log_buf_len=1M BOOT_IMAGE=/images/Fedora16/vmlinuz-3.1.6-1.fc16.i686

The "ignore-requirements" lines seems to have gone away but the mis-ordering of ntpdate remains.

Comment 11 Michal Schmidt 2012-04-25 07:12:55 UTC
Thanks.

[   29.919074] systemd[1]: Accepted connection on private bus.
[   29.919963] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.TryRestartUnit() on /org/freedesktop/systemd1
[   29.920036] systemd[1]: Trying to enqueue job ntpd.service/try-restart/replace
[   29.920135] systemd[1]: Installed new job ntpd.service/restart as 131
[   29.920153] systemd[1]: Enqueued job ntpd.service/try-restart as 131
[   29.921607] systemd[1]: About to execute: /usr/sbin/ntpd -n -u ntp:ntp $OPTIONS

This is probably /etc/dhcp/dhclient.d/ntp.sh calling "systemctl try-restart ntpd.service". It exposes a bug in systemd that we previously encountered with ypbind.

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


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