NTP Logging and Debugging API Manual (as on 10th Aug 2012)
Log messages can be logged to various channels
- Various Syslog Facilities
- local0, local1, …, local7
- Various Log Files that can specified by their paths
- A default file:
The NTP Logging Framework shall take most of its logging configuration by parsing the
configuration file. All the lines in
shall pertain to logging settings.
logging channel channel parameters
- logging : all config lines related to logging shall begin with this
- channel : Can be any of the following
- channel parameters : They are specific parameters pertaining to particular channel
- FACILITY : Specify the facility of SYSLOG about which we are talking
- PATH : Specify the path of the file
- 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
EMERGENCY are logged to
- 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
- If tags clause is not specified then all tags are logged
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
System Log Messages page in the documentation on the website, I found that currently the messages are classified as
. 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
are actually of type
, similarly for
, many of them are more of
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.
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
condition, considering so many clients depend on them. Introduction of
level shall be most useful to the developers in case of trying to debug something.
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
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");
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
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.
"verbose level" condition macro.
Verbose level condition macros
, behave analogous to
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.
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_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
- 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
- LOG_IF(severity, condition, tags, …) , LOG_ASSERT(condition)
- Conditional Logging, Assertion Fail Invokes : Macro LOG
- 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
- VLOG(debug_level, message, …), VLOG_IF(debug_level, condition, tags, message, …), VLOG_IS_ON(debug_level)
- Verbose Logging : Based on TRACE
- Invokes: Macro TRACE
- LOG_TO_FILE(severity, tags, …)
- File Logging
- Log to all specified File Logging Channels
- Invokes : Function add_to_log_file
- 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
- 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
- SYSLOG(severity, tags, message, …), SYSLOG_IF(severity, condition, tags, message, …), SYSLOG_ASSERT(condition)
- Syslog Logging
- Log to all specified Syslog Channels
- Invoke : Function msyslog
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