[SOLVED] ntpd logging to syslogd, fails to log panic_stop message

metaed · 06-15-2022, 06:10 PM

Slackware 15.0 is running as a guest on Windows 10 Hyper-V. The NTP daemon went down. The issue is that it took longer than it should have for us to figure out, because of a logging problem.

Overnight, the Windows host went down for a software update and turned itself off. Hours later, we discovered this and booted the Windows host. The Slackware 15.0 guest resumed, and the NTP daemon went down silently. We know the cause was the guest system clock now being hours behind the NTP peers. Downtime of more than 1000 seconds triggers an NTP panic_stop. But the NTP panic_stop message is missing from the log.

Otherwise, NTP has no trouble logging. For example, when the Windows host is booted, NTP on the guest logs a sequence of messages acknowledging that the eth0 interface changed.

Anybody know the cause of this missing log message?

henca · 06-16-2022, 01:16 AM

During the years I have seen this happen many times for different reasons, but as far as I can remember, there have allways been a message in syslog that the time difference is too big.

Reasons for big time difference might be that some machine doesn't have UTC time in its hardware clock and daylight saving has changed since last boot. Another common reason is a bad CMOS battery.

For this, I have written my own startup script for ntp which calls ntpdate before starting ntpd:

Code:

nazgul:/tmp> cat /usr/local/etc/rc.d/rc.ntpd
#!/bin/sh

if [ -x /usr/sbin/ntpd ]; then
  if [ -x /usr/sbin/ntpdate ]; then
    /usr/sbin/ntpdate balrog
  fi
  /usr/sbin/ntpd
fi

The above script is called from /etc/rc.d/rc.local. However, lately ntpd has been started with the switch -g from the original scripts. With that I don't think that ntpdate is needed anymore.

regards Henrik

metaed · 09-19-2022, 04:37 PM

The answer is that panic_stop is treated much differently from most ntpd messages associated with a fatal condition. Most fatal conditions are always syslogged at "err" severity before exiting. But panic_stop is conditionally logged, depending on the "sysevents" syslog filter, and at "info" severity.

According to bug 2410 at the NTP Bugzilla, this is a regression -- at one time, panic_stop was always logged. A patch is being considered for release ntp-4.2.8p16.

Meanwhile the workaround is to add a logconfig command to ntp.conf, to make sure the event is not filtered. A couple of possibilities:

# log the panic_stop condition and other system events
logconfig +sysevents

# better yet, disable syslog filtering so that this and any other such events get logged
logconfig =allall