Red Hat Bugzilla – Bug 481461
ntpd is too verbose in what it logs without debug flag
Last modified: 2010-11-03 14:37:18 EDT
ntpd is constantly putting messages like these in /var/log/messages:
Jan 24 20:59:06 free-spin ntpd: synchronized to 220.127.116.11, stratum 2
Jan 24 20:59:06 free-spin ntpd: time reset +0.286302 s
Jan 24 20:59:06 free-spin ntpd: kernel time sync status change 0001
Jan 24 21:03:56 free-spin ntpd: synchronized to 18.104.22.168, stratum 2
Jan 24 21:09:53 free-spin ntpd: synchronized to 22.214.171.124, stratum 2
Jan 24 21:20:01 free-spin ntpd: synchronized to 126.96.36.199, stratum 2
Jan 24 21:22:35 free-spin ntpd: synchronized to 188.8.131.52, stratum 2
Jan 24 21:23:11 free-spin ntpd: time reset -0.278128 s
Jan 24 21:32:07 free-spin ntpd: synchronized to 184.108.40.206, stratum 2
Jan 24 21:36:28 free-spin ntpd: synchronized to 220.127.116.11, stratum 2
Jan 24 21:38:41 free-spin ntpd: synchronized to 18.104.22.168, stratum 2
Jan 24 21:42:52 free-spin ntpd: time reset -0.266632 s
It looks like /etc/sysconfig/ntpd is not using -d or -D, which are flags that increase the logging level for debug-only messages. These messages which I find in my logs appear to be part of the normal operation of ntpd, therefore I think it would be appropriate to suppress them at the default (quiet) logging level, unless someone has a reason they are needed.
Sorry, I forgot to mention the current version number: ntp-4.2.4p6-2.fc11.x86_64
They are more than just debugging messages. When occurring frequently, they indicate a problem in timekeeping. Usually it's a hw or kernel problem. Was ntpd resetting time with older kernels?
Anyway, -l /dev/null in /etc/sysconfig/ntpd can be used to send all ntpd messages to /dev/null.
I see these kinds of messages going back as far as my logs, to around January 4, 2009, which was kernel-2.6.28-3.fc11.x86_64 or so.
My concern is mostly just to keep /var/log/messages tidy and useful for everyone, so I don't usually configure my test machine any differently from the defaults. (Though thanks for the suggested workaround.)
If these messages are meant to indicate an error condition that should be corrected, they need to be a bit more definite about that, and make some sort of suggestion for what to do next or where to look for more information. But if as you say, they only indicate a problem if they appear frequently, would it be appropriate for ntpd to keep track of such things, and print an affirmative "I have a problem" message if some threshold is passed?
I'm happy to provide whatever additional info you might need if you think there is another underlying bug, in addition to the message management question.
I'm afraid doing an automated analysis of the messages would be complicated. The messages could be considered normal in some situations, for example if there are big temperature changes in the oscillator, so its rate would change significantly.
To be sure it's a hw or kernel problem in your case, I need more information. Can you please stop ntpd service, remove /var/lib/ntp/drift, enable loopstats and peerstats in /etc/ntp.conf, start the service again, wait for at least two hours and attach here the files from /var/log/ntpstats and ntpd messages in syslog?
Created attachment 330465 [details]
I did the two-hour or so run as requested; attaching log files.
Created attachment 330466 [details]
Created attachment 330467 [details]
/var/log/messages (ntpd messages only)
It seems to be working ok, except the frequent server switching. Are the configured servers from pool.ntp.org? Can you try adding another server to ntp.conf, for example 3.fedora.pool.ntp.org?
ntp.conf had the following servers:
I'm doing a test run right now adding 3.fedora.pool.ntp.org.
Created attachment 344914 [details]
Sorry for the delay; here are the log files from the day of the previously mentioned test run.
Created attachment 344915 [details]
I don't see anything wrong in the logs. The frequent server switching is still in syslog?
Created attachment 345172 [details]
/var/log/messages from 29 Apr 2009
There are indeed still a large number of warnings in /var/log/messages; see attachment.
This bug appears to have been reported against 'rawhide' during the Fedora 11 development cycle.
Changing version to '11'.
More information and reason for this action is here:
ntp-4.2.6p1-0.1.rc5.fc14 is now rawhide.
In the new version it's possible to configure which events should be logged, and the default setting is less verbose than it used to.
(In reply to comment #15)
> ntp-4.2.6p1-0.1.rc5.fc14 is now rawhide.
> In the new version it's possible to configure which events should be logged,
> and the default setting is less verbose than it used to.
How do you accomplish this?
It's the logconfig directive, described in ntp_misc(5).
(In reply to comment #17)
> It's the logconfig directive, described in ntp_misc(5).
Thanks a bunch