What to Log

Owned by Prudence Au
Oct 14, 2019
3 min read

The purpose of logging is to capture diagnostic information.

An important aspect of this is analytics, which requires tracing of requests between components. In a large, distributed and scalable system such as ONAP this is critical to understanding behavior and performance. 

General 

It isn't the aim of this document to reiterate Best Practices, so advice here is general: 

  • Use a logging facade such as SLF4J or EELF. 

  • Write log messages in English.

  • Write meaningful messages. Consider what will be useful to consumers of logger output. 

  • Log at the appropriate level. Be aware of the volume of logs that will be produced.

  • Safeguard the information in exceptions, and ensure it is never lost.

  • Use errorcodes to characterise exceptions. 

  • Log in a machine-readable format. See Conventions.

  • Log for analytics as well as troubleshooting.

Others have written extensively on this: 

Standard Attributes

These are attributes common to all log messages. They are either:

  • Explicitly required by logging APIs:

    • Logger

    • Level

    • Message

    • Exception (note that exception is the only standard attribute that may routinely be empty).

  • Implicitly derived by the logging provider:

    • Timestamp

    • Thread.

Which means you normally can't help but report them. 

See https://www.slf4j.org/api/org/slf4j/Logger.html and https://logback.qos.ch/manual/layouts.html#ClassicPatternLayout for their origins and use.

Logger Name

This indicates the name of the logger that logged the message.

In Java it is convention to name the logger after the class or package using that logger.

  • In Java, report the class or package name.

  • In Python, the class or source filename.

Most other languages will fit one of those patterns. 

Level

Severity, typically drawn from the enumeration {TRACE, DEBUG, INFO, WARN, ERROR}.

Think carefully about the information you report at each log level. The default log level is INFO.

Some loggers define non-standard levels, like FINE, FINER, WARNING, SEVERE, FATAL or CRITICAL. Use these judiciously, or avoid them.

Message

The free text payload of a log event. 

This is the most important item of information in most log messages. See General guidelines.

Internationalization

Diagnostic log messages generally do not need to be internationalized.

Parameterization

Parameterized messages allow serialization to be deferred until AFTER level threshold checks. This means the cost is never incurred for messages that won't be written. 

  • Favor parameterized messages, especially for INFO and DEBUG logging.

  • Perform expensive serialization in the #toString method of wrapper classes.

For example:

logger.debug("Relax - this won't hurt: {}", new ToStringWrapper(costlyToSerialize));

Exception

The error stacktrace, where applicable.

Log unabridged stacktraces upon error.

When rethrowing, ensure that frame information is not lost:

  • By logging the original exception at the point where it was caught. 

  • By setting the original exception as the cause when rethrowing.

Timestamp

Logged as an ISO8601 UTC datetime. Millisecond (or greater) precision is preferable.

For example:

2018-07-05T20:21:34.794Z

Offset timestamps are OK provided the offset is included. (In the above example, the "Z" is a shorthand indicating an offset of zero – UTC).

Thread

The name of the thread from which the log message was emitted.

Thread names don't necessarily convey useful information, and their reliability depends on the thread model implemented by different runtimes, but they are sometimes used in heuristic analysis.

Efficiency

There is tension between utility and efficiency. IO bandwidth is finite, and the cost of serialization can be significant, especially at higher diagnostic levels.

Methods and Line Numbers

Many loggers can use reflection to emit the originating (Java) method, and even individual line numbers.

This information is certainly useful, but very expensive. Most logging implementations recommend that this not be enabled in production.

Level Thresholds

Level indicates severity.

Logger output is typically filtered by logger and level. The default logging level is INFO, so particular consideration should be given to the efficiency of INFO-level logging.

When DEBUG-level logging is configured, it's probably for good reason, and a greater overhead is expected. Be aware that it's not unusual for DEBUG logging to be left enabled inadvertently, however.

WARN and ERROR-level messages are of higher value, and comparatively rare, so their cost is less of a concern.

Conditionals

A common pattern is to place conditionals around (expensive) serialization.

For example:

if (logger.isDebugEnabled()) { logger.debug("But this WILL hurt: " + costlyToSerialize); }

Parameterized logging is preferable.