r5 - 2013-10-13 - 06:53:21 - HarlanStennYou are here: NTP >  Dev Web > GoogleSummerOfCode > GSoC2012LoggingDebugging > GSoC2012LoggingDebuggingAPIManual
NTP users are strongly urged to take immediate action to ensure that their NTP daemons are not susceptible to being used in distributed denial-of-service (DDoS) attacks. Please also take this opportunity to defeat denial-of-service attacks by implementing Ingress and Egress filtering through BCP38.

ntp-4.2.8p13 was released on 07 March 2019. It addresses 1 medium-severity security issue in ntpd, and provides 17 non-security bugfixes and 1 other improvements over 4.2.8p12.

Please see the NTP Security Notice for vulnerability and mitigation details.

Are you using Autokey in production? If so, please contact Harlan - he's got some questions for you.

NTP Logging and Debugging API Manual (as on 10th Aug 2012)

Log messages can be logged to various channels

  • SYSLOG
    • Various Syslog Facilities
      • auth
      • authpriv
      • console
      • daemon
      • ntp
      • local0, local1, …, local7
  • FILE
    • Various Log Files that can specified by their paths
    • A default file: /var/log/ntp.log
  • TERMINAL
    • stdout
    • stderr

Configuration

The NTP Logging Framework shall take most of its logging configuration by parsing the ntp.conf configuration file. All the lines in ntp.conf beginning with logging shall pertain to logging settings.

logging channel channel parameters severities minimum_allowed_severities tags allowed_tags

  • logging : all config lines related to logging shall begin with this
  • channel : Can be any of the following
    • SYSLOG
    • FILE
    • TERMINAL
  • channel parameters : They are specific parameters pertaining to particular channel
    • SYSLOG
      • FACILITY : Specify the facility of SYSLOG about which we are talking
    • FILE
      • PATH : Specify the path of the file
    • TERMINAL
      • stdout/stderr/some remote screen
  • severities : optional
    • minimum_allowed_severity : Specify the severity from which we want to log the messages to a particular channel.
    • For example, if we specify logging FILE "/tmp/dummy" severities ERROR, then only messages with severity ERROR and above, like CRITICAL, ALERT, EMERGENCY are logged to /tmp/dummy.
    • If the severity clause is not specified then all severities are logged
  • tags : optional
    • allowed_tags : these are the tags that need be logged to the particular channel
    • The allowed tags should be a list enclosed within (), {}, or []
    • If tags clause is not specified then all tags are logged

Severity Levels

The severity levels used are the ones that are used in the SYSLOG namely

  • EMERGENCY A "panic" condition usually affecting multiple apps/servers/sites. At this level it would usually notify all tech staff on call.
  • ALERT Should be corrected immediately, therefore notify staff who can fix the problem. An example would be the loss of a backup ISP connection.
  • CRITICAL/FATAL Should be corrected immediately, but indicates failure in a primary system, an example is a loss of primary ISP connection.
  • ERROR Non-urgent failures, these should be relayed to developers or admins; each item must be resolved within a given time.
  • WARNING Warning messages, not an error, but indication that an error will occur if action is not taken, e.g. file system 85% full - each item must be resolved within a given time.
  • NOTICE Events that are unusual but not error conditions - might be summarized in an email to developers or admins to spot potential problems - no immediate action required.
  • INFO Normal operational messages - may be harvested for reporting, measuring throughput, etc. - no action required.
  • DEBUG Info useful to developers for debugging the application, not useful during operations.

Going over the ntpd System Log Messages page in the documentation on the website, I found that currently the messages are classified as INFO, NOTICE, ERROR. So, from this I deduce that mostly the messages are one these three types of severity. However, I feel that many of the messages currently classified under ERROR are actually of type CRITICAL, similarly for NOTICE and ERROR, many of them are more of WARNING type. So, it shall be better if we can introduce these two levels, for want of better classification. HMS: Until we can find a way to allow the local admin to change the severity of a message we should leave the current severities alone.

For the ALERT and EMERGENCY types, they can be needed at primary servers in stratum 1 or stratum 2, if something goes wrong there, as that shall actually be a prime EMERGENCY or ALERT condition, considering so many clients depend on them. Introduction of DEBUG level shall be most useful to the developers in case of trying to debug something.

Conditional Logging

Sometimes, you may only want to log a message under certain conditions. You can use the following macros to perform conditional logging:

LOG_IF(INFO, num_cookies > 10, "Got lots of cookies");

The "Got lots of cookies" message is logged only when the variable num_cookies exceeds 10. If a line of code is executed many times, it may be useful to only log a message at certain intervals.

Debug Mode Support

Special "debug mode" logging macros only have an effect in debug mode and are compiled away to nothing for non-debug mode compiles. Use these macros to avoid slowing down your production application due to excessive logging.

DPRINTF(INFO, "Found cookies");

DPRINTF_IF(INFO, num_cookies > 10, "Got lots of cookies");

Verbose Logging

When you are chasing difficult bugs, thorough log messages are very useful. However, you may want to ignore too verbose messages in usual development. For such verbose logging, glog provides the TRACE macro, which allows you to define your own numeric logging levels.

TRACE(1, "I'm printed when you run the program with --v=1 or higher");

TRACE(2, "I'm printed when you run the program with --v=2 or higher");

With TRACE and DPRINTF, the lower the verbose level, the more likely messages are to be logged. For example, if -d is passed, TRACE(1) will log, but TRACE(2) will not log. This is opposite of the severity level, where INFO is 0, and ERROR is 2. 1 will log WARNING and above. Though you can specify any integers for both TRACE and DPRINTF macro and flag, the common values for them are small positive integers.

VLOG is synonymous to TRACE.

There's also VLOG_IS_ON(n) "verbose level" condition macro.

Verbose level condition macros VLOG_IF, behave analogous to LOG_IF but accepts a numeric verbosity level as opposed to a severity level.

VLOG_IF(1, (size > 1024), "I'm printed when size is more than 1024 and when you run the " "program with --v=1 or more");

Tagging of Logs

The new API shall be very tag-centric. The decision whether to log a particular message to a channel shall depend on its tags. The tags shall also be for classification of various logs. These tags can be categories to which the log messages may belong. The tags are passed to logging macro and further on to to the logger function as a string. This string is placed in the log line and logged along with the log message.

Miscellaneous Notes

Performance of Messages

The conditional logging macros provided (e.g.LOG_IF, VLOG, ...) are carefully implemented and don't execute the complete expressions when the conditions are false. So, the following check may not sacrifice the performance of the application.

Syslog

SYSLOG, SYSLOG_IF, and SYSLOG_EVERY_N macros are defined. These log to syslog. The functionality for the SYSLOG logging is built upon the already implemented and tested msyslog module already within NTP, as the module serves all the requirements and niceties for logging to syslog. But logging to syslog can drastically impact performance, especially if syslog is configured for remote logging! In general, it's wise to use these macros sparingly.

Strip Logging Messages

Strings used in log messages can increase the size of your binary and present a privacy concern. You can therefore instruct glog to remove all strings which fall below a certain severity level by using the STRIP_LOG macro: If your application has code like this: #define STRIP_LOG 1 // this must go before the #include! The compiler will remove the log messages whose severities are less than the specified integer value. Since VLOG logs at the severity level INFO (numeric value 0), setting STRIP_LOG to 1 or greater removes all log messages associated with VLOGs as well as INFO log statements.

MACROS defined and that can be used

  1. LOG(severity, tags, …)
    • LOG_D, LOG_I, LOG_N, LOG_W, LOG_E, LOG_C, LOG_A, LOG_EM
    • General Logging Invoke: Functions – add_to_log_file, Macros – SYSLOG, LOG_TO_TERMINAL
    • LOG to all specified logging channels
  2. LOG_IF(severity, condition, tags, …) , LOG_ASSERT(condition)
    • Conditional Logging, Assertion Fail Invokes : Macro LOG
  3. DLOG(debug_level, message, …), DLOG_IF(debug_level, condition, message, …) , DLOG_ASSERT(condition), DLOG_IS_ON(debug_level)
    • Debug Level Logging : Based on DPRINTF
    • Invokes : Macro DPRINTF
  4. VLOG(debug_level, message, …), VLOG_IF(debug_level, condition, tags, message, …), VLOG_IS_ON(debug_level)
    • Verbose Logging : Based on TRACE
    • Invokes: Macro TRACE
  5. LOG_TO_FILE(severity, tags, …)
    • File Logging
    • Log to all specified File Logging Channels
    • Invokes : Function add_to_log_file
  6. LOG_TO_SINK(severity, tags, …), LOG_SINK(severity, tags, …), LOG_TO_SINK_BUT_NOT_TO_LOGFILE(severity, tags, …)
    • Sink Logging
    • Invoke : Function add_log_to_sink
  7. LOG_TO_TERMINAL (severity, tags, …), LOG_TO_STDOUT(severity, tags, …), LOG_TO_STDERR(severity, tags, …)
    • Terminal Logging
    • Log to all specified Terminal Logging Channels
    • Invoke : Functions add_log_to_stdout, add_log_to_stderr
  8. SYSLOG(severity, tags, message, …), SYSLOG_IF(severity, condition, tags, message, …), SYSLOG_ASSERT(condition)
    • Syslog Logging
    • Log to all specified Syslog Channels
    • Invoke : Function msyslog

LOG FORMAT

  • SYSLOG Date Time ComputerName process[pid]: Message [System Error Message]
  • LOG FILE: Date Time user ComputerName pid: func: SevLvl Tags: Message [System Error Message]

Changes to DPRINTF and TRACE

Add tags to the messages

Major Logging Functions

  • format_log : Formats log messages for logging to Log File
  • addto_log_file : Add log messages to all logging channels
  • add_log_to_stdout : Add log messages to stdout
  • add_log_to_stderr : Add log messages to stderr
  • add_log_to_sink : Add log messages to sink
  • msyslog

-- RajulSrivastava - 2012-08-10

 

The new API shall be very tag-centric. The decision whether to log a particular message to a channel shall depend on its tags. The tags shall also be for classification of various logs. These tags can be categories to which the log messages may belong. The tags are passed to logging macro and further on to to the logger function as a string. This string is placed in the log line and logged along with the log message.

Edit | WYSIWYG | Attach | Printable | Raw View | Backlinks: Web, All Webs | History: r5 < r4 < r3 < r2 < r1 | More topic actions
Dev.GSoC2012LoggingDebuggingAPIManual moved from Dev.GSoC2011LoggingDebuggingAPIManual on 2012-08-20 - 00:17 by RajulSrivastava - put it back
 
SSL security by CAcert
Get the CAcert Root Certificate
This site is powered by the TWiki collaboration platform
IPv6 Ready
Copyright & 1999-2020 by the contributing authors. All material on this collaboration platform is the property of the contributing authors. Ideas, requests, problems regarding the site? Send feedback