NTP ntpd 4.2.8p15
Slackware Linux 15.0

It took longer than it should have to figure out that ntpd was not running and why. ntpd exited with a panic_stop condition, but there was nothing in syslog. Once we understood what happened, it was easy to reproduce. Other messages from ntpd were routinely logged, but panic_stop was not logged.

Just to be clear, I understand why we got a panic_stop and I solved that. We didn't understand why a fatal error wasn't logged, when other messages, both fatal and non-fatal, were logged.

After a good bit of code reading, I decided that the panic_stop message is treated much differently from most ntpd messages associated with a fatal condition, in two ways.

(1) Messages associated with most fatal conditions are logged, without filtering, before the exit() call. But panic_stop is logged only when the syslog filter has "+sysevents". Strangely, that's not the out-of-box filter setting.

(2) Messages associated with most fatal conditions have a syslog severity of 3 "error". But panic_stop messages have a much lower syslog severity of 6 "info". That is lower even than "notice" which means "normal but significant condition".

I can't rely on the default filter setting to log a fatal condition, so as a precaution I turned off filtering: "logconfig =allall". Given the importance of fatal conditions, perhaps this can be made the out-of-box default, not "logconfig =syncall".

And perhaps the severity associated with the panic_stop message can be changed to "error", not "info". An exit() call does not in any useful way leave the ntpd daemon in a "normal but significant condition".

But the report_event() routine utilized by the panic_stop condition does not currently take a severity as an argument. It simply logs all sysevents at severity "info". So this would be kind of a big deal to patch.

I wanted to document this for anyone who might depend on syslog to monitor and diagnose problems with ntpd. Also I could have some wrong perceptions about what is going on with ntpd logging in general, and panic_stop logging in particular, so if you see something, please point it out.

Cheers!
Edward

Open a report at bugs.ntp.org (gmail users probably need to be manually
approved because we get far too many spammers opening spam bug reports
otherwise) and it will likely be fixed in the upcoming p16.

H

On 9/16/2022 1:16 PM, Edward McGuire wrote:
> NTP ntpd 4.2.8p15
> Slackware Linux 15.0
>
> It took longer than it should have to figure out that ntpd was not running and why. ntpd exited with a panic_stop condition, but there was nothing in syslog. Once we understood what happened, it was easy to reproduce. Other messages from ntpd were routinely logged, but panic_stop was not logged.
>
> Just to be clear, I understand why we got a panic_stop and I solved that. We didn't understand why a fatal error wasn't logged, when other messages, both fatal and non-fatal, were logged.
>
> After a good bit of code reading, I decided that the panic_stop message is treated much differently from most ntpd messages associated with a fatal condition, in two ways.
>
> (1) Messages associated with most fatal conditions are logged, without filtering, before the exit() call. But panic_stop is logged only when the syslog filter has "+sysevents". Strangely, that's not the out-of-box filter setting.
>
> (2) Messages associated with most fatal conditions have a syslog severity of 3 "error". But panic_stop messages have a much lower syslog severity of 6 "info". That is lower even than "notice" which means "normal but significant condition".
>
> I can't rely on the default filter setting to log a fatal condition, so as a precaution I turned off filtering: "logconfig =allall". Given the importance of fatal conditions, perhaps this can be made the out-of-box default, not "logconfig =syncall".
>
> And perhaps the severity associated with the panic_stop message can be changed to "error", not "info". An exit() call does not in any useful way leave the ntpd daemon in a "normal but significant condition".
>
> But the report_event() routine utilized by the panic_stop condition does not currently take a severity as an argument. It simply logs all sysevents at severity "info". So this would be kind of a big deal to patch.
>
> I wanted to document this for anyone who might depend on syslog to monitor and diagnose problems with ntpd. Also I could have some wrong perceptions about what is going on with ntpd logging in general, and panic_stop logging in particular, so if you see something, please point it out.
>
> Cheers!
> Edward

--
Harlan Stenn <stenn@nwtime.org>
http://networktimefoundation.org - be a member!
--
This is questions@lists.ntp.org
Subscribe: questions+subscribe@lists.ntp.org
Unsubscribe: questions+unsubscribe@lists.ntp.org

On Friday, September 16, 2022 at 6:18:02 PM UTC-5, Harlan Stenn wrote:
> Open a report at bugs.ntp.org (gmail users probably need to be manually
> approved [...]) and it will likely be fixed in the upcoming p16.

Thank you Harlan. And thanks to justdave who helped me get credentialed at bugs.ntp.org.

The process of opening a report surfaced bug no. 2410, "The ntpd daemon should never abnormally exit without logging a ERR level message". I believe my experience does not warrant a separate report because it is a duplicate of 2410. I will add a comment there including a simple proposal for solving this.

Please consider bug 2410 for p16.

Cheers!
Edward