Table of Contents |
---|
...
- 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 assumed, but conventions may be implemented by non-Java components. For example our new python library provided by the Multicloud team is coming into Beijing under Jira Legacy server System Jira serverId 4733707d-2057-3a0f-ae5e-4fd8aff50176 key MULTICLOUD-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 can be is being deployed using ONAP Operations Manager. Operations Manager since the amsterdam release - see usage in Logging Analytics Dashboards (Kibana)
This document gives 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.
...
Log4j 2.X is somewhat less common than Logback, but equivalent. It is generally configured by an XML document named log4j.xml. See Configuration.
Log4j 1.X
Strongly discouraged from Beijing onwards, since 1.X is EOL, and since it does not support escaping, so its output may not be machine-readable. See https://logging.apache.org/log4j/1.2/.
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).
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, distributedand scalable system such as ONAP this is critical to understanding behavior and performance.
...
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 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).
...
- 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: add framework derived column (where the logging framework would handle a particular MDC)
TODO: cross-reference EELF output to v1 doc.fill out the EELF columns
TODO: add junit tests
ID | MDC | Description | Required | EELF Audit | EELF Metric | EELF Error | EELF Debug |
---|---|---|---|---|---|---|---|
RequestID | See above. | Y | |||||
InvocationID | See above. | Y | |||||
ServiceName | See above. | Y | |||||
PartnerName | See above. | Y | |||||
1 | BeginTimestamp | Date-time that processing activities being logged begins. The value should be represented in UTC and formatted per ISO 8601, such as “2015-06-03T13:21:58+00:00”. The time should be shown with the maximum resolution available to the logging component (e.g., milliseconds, microseconds) by including the appropriate number of decimal digits. For example, when millisecond precision is available, the date-time value would be presented as, as “2015-06-03T13:21:58.340+00:00”. framework candidate | Y | ||||
2 | EndTimestamp | Date-time that processing for the request or event being logged ends. Formatting rules are the same as for the BeginTimestamp field above. In the case of a request that merely logs an event and has not done subsequent processing, the EndTimestamp value may equal the BeginTimestamp value. framework candidate | Y | ||||
3 | ElapsedTime | This field contains the elapsed time to complete processing of an API call or transaction request (e.g., processing of a message that was received). This value should be the difference between. EndTimestamp and BeginTimestamp fields and must be expressed in milliseconds. | Y | ||||
4 | ServiceInstanceID | This field is optional and should only be included if the information is readily available to the logging component. Transaction requests that create or operate on a particular instance of a service/resource can
NOTE: AAI won’t have a serviceInstanceUUID for every service instance. For example, no serviceInstanceUUID is available when the request is coming from an application that may import inventory data. | |||||
5 | VirtualServerName | Physical/virtual server/K8S-container name. Optional: empty if determined that its value can be added by the agent that collects the log files collecting. Upgrade for kubernetes namespace, host affinity Duplcate of 13 - heat specific | |||||
6 | StatusCode | This field indicates the high level status of the request. It must have the value COMPLETE when the request is successful and ERROR when there is a failure. | Y | ||||
7 | ResponseCode | This field contains application-specific error codes. For consistency, common error categorizations should be used. | |||||
8 | ResponseDescription | This field contains a human readable description of the ResponseCode. | 11 | ||||
9 | InstanceUUID | If known, this field contains a universally unique identifier used to differentiate between multiple instances of the same (named) log writing service/application. Its value is set at instance creation time (and read by it, e.g., at start/initialization time from the environment). This value should be picked up by the component instance from its configuration file and subsequently used to enable differentiation of log records created by multiple, locally load balanced ONAP component or subcomponent instances that are otherwise identically configured. | |||||
10 | Severity | Optional: 0, 1, 2, 3 see Nagios monitoring/alerting for specifics/details. | |||||
11 | TargetEntity | It contains the name of the ONAP component or sub-component, or external entity, at which the operation activities captured in this metrics log record is invoked. | Y | ||||
12 | TargetServiceName | It contains the name of the API or operation activities invoked at the TargetEntity. | Y | ||||
13 | Server | This field contains the Virtual Machine (VM) Fully Qualified Domain Name (FQDN) if the server is virtualized. Otherwise, it contains the host name of the logging component. Upgrade for kubernetes namespace, host affinity heat specific | Y | ||||
14 | ServerIPAddress | This field contains the logging component host server’s IP address if known (e.g. Jetty container’s listening IP address). Otherwise it is empty. Upgrade for kubernetes namespace, host affinity, nodeport | |||||
15 | ServerFQDN | Unclear, but possibly duplicating one or both of Server and ServerIPAddress. Upgrade for kubernetes namespace, host affinity | |||||
16 | ClientIPAddress | This field contains the requesting remote client application’s IP address if known. Otherwise this field can be empty. | |||||
17 | ProcessKey | This field can be used to capture the flow of a transaction through the system by indicating the components and operations involved in processing. If present, it can be denoted by a comma separated list of components and applications. | |||||
18 | RemoteHost | Unknown. | |||||
19 | AlertSeverity | Unknown. | |||||
20 | TargetVirtualEntity | Unknown | |||||
21 | ClassName | Defunct. Doesn't require an MDC. | |||||
22 | ThreadID | Defunct. Doesn't require an MDC. | |||||
23 | CustomField1 | (Defunct now that MDCs are serialized as NVPs.(Name Value Pairs) | |||||
24 | CustomField2 | (Defunct now that MDCs are serialized as NVPs.) | |||||
25 | CustomField3 | (Defunct now that MDCs are serialized as NVPs.) | |||||
26 | CustomField4 | (Defunct now that MDCs are serialized as NVPs.) |
Examples
SDC-BE
20170907: audit.log - reverify for 201803
Code Block |
---|
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> |
...
- They have a name, but no value. They are a tag - like a label.
- Their scope is limited to logger calls which specifically reference them; they are not ThreadLocal. (TODO: validate InheritableThreadLocal for spawned child threads)
Logging
Via SLF4J:
Code Block | ||||
---|---|---|---|---|
| ||||
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:
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
final EELFLogger logger = EELFManager.getAuditLogger(); logger.auditEvent("Entering."); |
...
It must be manually set otherwise. Candidate for Framework
EELF:
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
final EELFLogger logger = EELFManager.getMetricsLogger(); logger.metricsEvent("Exiting."); |
...
Errorcodes are reported as MDCs. .
TODO: add to table
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: expand on JSON
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
Code Block | ||||
---|---|---|---|---|
| ||||
/var/log/ONAP_EELF/<component>[/<subcomponent>]/*.log |
...
Configuration archetypes can be found in the ONAP codebase (TODO: post git.onap.org tree location). 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 this procedure to the Project Proposal Template
By following a few simple rules:
...
- Field separator reverted to pipe.
- Dual appenders in Logback and Log4j reference configurations:
- Indexable, for shipping and indexing.
- EELF, for backward compatibility.
- Minor changes to path conventions.
- XML output deprecated (required only for Log4j1.2, which is also expected to go).
- 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.
- Add MDCs/Markers + usage for invocation IDs, allowing call graphs to be built without reliance on heuristics.
- Revisiting persistence (a clear requirement) and rollover settings, based on feedback from operations.
- More discussion of How to Log. (Where previously guidelines were largely concerned with architecture and mechanics).
- 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).
...