...

This document specifies logging conventions to be followed by ONAP component applications.  

This document is undergoing changes for Casablanca - see general edits for questions in color

...

...

ONAP logging is intended to support operability, debugging and reporting on ONAP. These guidelines address:

• Events that are written by ONAP components.
• Propagation of transaction and invocation information between components.
• MDCs, Markers and other information that should be attached to log messages.
  • MDC = Mapped Diagnostic Context
• Human- and machine-readable output format(s).
• Files, locations and other conventions. 

Java is assumedand Python are supported, but conventions may be implemented by non-Java componentsother technologies like GO.   For example our new python library provided by the Multicloud team is coming into Beijing under  JiraserverONAP JIRAserverId425b2b0a-557c-3c0c-b515-579789cceedbkeyMULTICLOUD-151

Original AT&T ONAP Logging guidelines: https://wiki.onap.org/download/attachments/1015849/ONAP%20application%20logging%20guidelines.pdf?api=v2

...

A reference configuration of Elastic Stack is being deployed using ONAP Operations Manager since the amsterdam release - see usage in Logging Analytics Dashboards (Kibana)

This document proposes proposes conventions you can follow to generate conformant, indexable logging output from your component.

...

EELF also logs via SLF4J's abstractions as the default provider.

Providers

Logging providers are normally enabled by their presence in the classpath. This means the decision may have been made for you, in some cases implicitly by dependencies. If you have a strong preference then you can change providers, but since the implementation is typically abstracted behind EELF or SLF4J, it may not be worth the effort.

...

This affects OpenDaylight-based components like SDNC and APPC, since ODL releases prior to Carbon bundled Log4j 1.X, and make it difficult to replace. The Common Controller SDK Project project targets ODL Carbon, so remaining instances of Log4j 1.X should disappear by the time of the Beijing release (TODO: 20180326 verify this is true).Casablanca release.

What to Log

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. 

...

• http://www.masterzen.fr/2013/01/13/the-10-commandments-of-logging/
• https://www.loggly.com/blog/how-to-write-effective-logs-for-remote-logging/
• And so on.

Context

TODO: more on the importance of transaction ID propagation and its relation to Invocation ID.

MDCs

A Mapped Diagnostic Context (MDC) allows an arbitrary string-valued attribute to be attached to a Java thread via a ThreadLocal variable. The MDC's value is then emitted with each message logged by that thread. The set of MDCs associated with a log message is serialized as unordered name-value pairs (see Text Output).

...

• It's only a few calls. 
• It can be largely abstracted in the case of EELF logging.

...

• .
  
  

MDC - PartnerName

This field should contain the name of the client application user agent or user invoking the API.

...

• Use the short name of your component, e.g. xyzdriver. (try to incorporate both levels - the container name and the pod the container is in within the kubernetes deployment)
• Values should be human-readable. 
• Values should be fine-grained enough to disambiguate subcomponents where it's likely to matter. This is subjective. 
• Be consistent: your component should ALWAYS report same value. 

...

Certain MDCs and their semantics may be specific to EELF log types.

TODO: fill out the EELF columns

TODO: add junit tests

review: 

Note: Log message order column represents log message line order (independent of MDC's)

...

  
Some of that is contentious, but it's just talking points at this stage. We've tiptoed around the issue of extant conventions, and the ongoing result is a lot of attributes that nobody's really sure how to use, and which don't result in better logs. In Casablanca it's time to be less conservative. 

Examples

SDC-BE

20170907: audit.log - reverify for 201803

root@ip-172-31-93-160:/dockerdata-nfs/onap/sdc/logs/SDC/SDC-BE# tail -f audit.log
2017-09-07T18:04:03.679Z|||||qtp1013423070-72297||ASDC|SDC-BE|||||||N/A|INFO||||10.42.88.30||o.o.s.v.r.s.VendorLicenseModelsImpl||ActivityType=<audit>, Desc=< --Audit-- Create VLM. VLM Name: lm4>

...

time to be less conservative. 

Examples

SDC-BE

Markers

Markers differ from MDCs in two important ways:

1. They have a name, but no value. They are a tag - like a label. 
2. Their scope is limited to logger calls which specifically reference them; they are not ThreadLocal. 

...

(Markers are attached to individual messages. They don't propagate. A code example will help, but note that EELF's implementation can be modified to emit Markers, but its public APIs do not allow them to be passed in by callers.)

Logging

Via SLF4J:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import org.slf4j.MarkerFactory;
// ...
final Logger logger = LoggerFactory.getLogger(this.getClass());
final Marker marker = MarkerFactory.getMarker("MY_MARKER");
logger.warn(marker, "This warning has a 'MY_MARKER' annotation.");

...

It must be manually set otherwise. Candidate for Framework 

EELF:

final EELFLogger logger = EELFManager.getMetricsLogger();
logger.metricsEvent("Exiting.");

...

public static final Marker INVOKE = MarkerFactory.getMarker("INVOKE");
// ...

// Generate and report invocation ID. 

final String invocationID = UUID.randomUUID().toString();
MDC.put(MDC_INVOCATION_ID, invocationID);
try {
    logger.debug(INVOKE_SYNCHRONOUS, "Invoking synchronously ... ");
}
finally {
    MDC.remove(MDC_INVOCATION_ID);
}

// Pass invocationID as HTTP X-InvocationID header.

callDownstreamSystem(invocationID, ... );

TODO: EELF examples of INVOCATION_ID reporting, without changing published APIs.

Marker - INVOKE-RETURN

This should be reported by the caller of another ONAP component via REST on return.

...

public TBD

Marker - INVOKE-SYNCHRONOUS

...

public static final Marker INVOKE_SYNCHRONOUS;
static {
    INVOKE_SYNCHRONOUS = MarkerFactory.getMarker("INVOKE");
    INVOKE_SYNCHRONOUS.add(MarkerFactory.getMarker("SYNCHRONOUS"));
}
// ...

// Generate and report invocation ID. 

final String invocationID = UUID.randomUUID().toString();
MDC.put(MDC_INVOCATION_ID, invocationID);
try {
    logger.debug(INVOKE_SYNCHRONOUS, "Invoking synchronously ... ");
}
finally {
    MDC.remove(MDC_INVOCATION_ID);
}

// Pass invocationID as HTTP X-InvocationID header.

callDownstreamSystem(invocationID, ... );

TODO: EELF example of SYNCHRONOUS reporting, without changing published APIs. 

Errorcodes

Errorcodes are reported as MDCs. 

...

Exceptions should be accompanied by an errrorcode. Typically this is achieved by incorporating errorcodes into your exception hierarchy and error handling. ONAP components generally do not share this kind of code, though EELF defines a marker interface (meaning it has no methods) EELFResolvableErrorEnum. (a framework candidate)

A common convention is for errorcodes to have two components:

...

For Log4j 1.X output, since escaping is not supported, the best alternative is to emit logs in XML format. TODO: , we will expand on JSON support

There may be other instances where XML (or JSON) output may be desirable. Default indexing rules support 

...

Standardization of output locations makes logs easier to locate and ship for indexing. 

TODO: Expand on out-of-container locations off /dockerdata-nfs

Logfiles should default to beneath /var/log, and beneath /var/log/ONAP in the case of core ONAP components:

...

For the duration of Beijing, logs  will be written to a separate directory, /var/log/ONAP_EELF:

TODO: expand on Casablanca differences, and adding as a config setting in OOM

/var/log/ONAP_EELF/<component>[/<subcomponent>]/*.log

...

Configuration archetypes can be found in the ONAP codebase (TODOhttps: post //git.onap.org tree location)/logging-analytics/tree/. Choose according to your provider, and whether you're logging via EELF. Efforts to standardize them are underway (TODO: link to specific epics), so the ones you should be looking for are where pipe (|) is used as a separator. (Previously it was "|").

...

• The need to index logs before they're removed. (TODO: provide saturation testing)
• The need to retain logs for other (including regulatory) purposes. 

...

New ONAP Component Checklist

TODO: add Add this procedure to the Project Proposal Template

By following a few simple rules:

...

1. Field separator reverted to pipe. 
2. Dual appenders in Logback and Log4j reference configurations:
   1. Indexable, for shipping and indexing. 
   2. EELF, for backward compatibility. 
   3. Minor changes to path conventions.
3. XML output deprecated (required only for Log4j1.2, which is also expected to go).
4. Improved documentation of semantics and usage (including initialization and propagation via ThreadLocal (Verify InheritableThreadLocal copy into spawned threads) and HTTP headers) for existing MDCs and attributes. 
5. Add MDCs/Markers + usage for invocation IDs, allowing call graphs to be built without reliance on heuristics.
6. Revisiting persistence (a clear requirement) and rollover settings, based on feedback from operations. 
7. More discussion of How to Log. (Where previously guidelines were largely concerned with architecture and mechanics).
8. Locking in other changes proposed in R1, including MDC serialization, escaping, etc. These can be treated as accepted. (Note that they only affect indexable output).

...