...
id | date | item | details | status |
---|---|---|---|---|
20180614 | MDC ClientIPAddress | Ask question of OPS to remove this field - 20180419 | todo | |
20180614 | MDC ResponseCode / ResponseDescription | expand/find note 1* | todo |
Developer Guide
See additional developer/deployment oriented details on ONAP Development
Luke Parker has added a logging library and example project that exposes a 3rd party jar in nexus.onap.org at https://nexus.onap.org/service/local/repositories/snapshots/content/org/onap/logging-analytics/logging-slf4j/1.2.0-SNAPSHOT/logging-slf4j-1.2.0-20180627.052542-13.jar
Do we need to use this library? good question – you have 4 options (unchanged, do your own code changes/library, use the SLF4J library from Luke (includes MDC/Marker support) or use the AOP (WIP) wrapper on the SLF4J library – it uses aspects to (so-far) add ENTRY/EXIT marker (labelled) logs for each function call in scope. Using the library is optional – the goal is to reduce the amount of work teams need to do to adhere to the new MDC/Marker specification for Casablanca.
There are developer details on using the libraries (pom.xml edits, spring AOP additions) and how to deploy the logdemo pod alongside onap that demos using the libraries
The code is ready for use as we finish the library (java is most up to date for now, python is in progress)
https://git.onap.org/logging-analytics/tree/reference
The demo RI stack
oom kubernetes chart
https://git.onap.org/logging-analytics/tree/reference/logging-kubernetes
docker build
https://git.onap.org/logging-analytics/tree/reference/logging-docker-root/logging-docker-demo
war
https://git.onap.org/logging-analytics/tree/reference/logging-demo
aop library
https://git.onap.org/logging-analytics/tree/reference/logging-library
slf4j library
https://git.onap.org/logging-analytics/tree/reference/logging-slf4j
Overall Logging and ELK Architecture
Adding Filebeat to an ONAP Kubernetes POD
See commit https://gerrit.onap.org/r/#/c/57171/ for
Jira | ||||||
---|---|---|---|---|---|---|
|
Artifacts
Consumed
Logging Library JAR
Logging Library AOP wrapper JAR
logback.xml
filebeat.yml
Produced
Microservice WAR - using the Logging Library AOP JAR
DockerFile
Helm Charts for Kubernetes
Adding Logging to a WAR Project
Logback.xml
place in src/main/java/resources
based off https://git.onap.org/logging-analytics/tree/reference/logging-slf4j/src/test/resources/logback.xml
But don't use this file yet until it is finished testing and the indexing is modified on the ELK side - https://gerrit.onap.org/r/#/c/57171/
Until then you can continue to use the same logback.xml used by other components that already log like portal/policy/aai/vid/clamp
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
#WIP
<configuration scan="false" debug="true">
<property name="p_tim" value="%d{"yyyy-MM-dd'T'HH:mm:ss.SSSXXX", UTC}"/>
<property name="p_lvl" value="%level"/>
<property name="p_log" value="%logger"/>
<property name="p_mdc" value="%replace(%replace(%mdc){'\t','\\\\t'}){'\n', '\\\\n'}"/>
<property name="p_msg" value="%replace(%replace(%msg){'\t', '\\\\t'}){'\n','\\\\n'}"/>
<property name="p_exc" value="%replace(%replace(%rootException){'\t', '\\\\t'}){'\n','\\\\n'}"/>
<property name="p_mak" value="%replace(%replace(%marker){'\t', '\\\\t'}){'\n','\\\\n'}"/>
<property name="p_thr" value="%thread"/>
<property name="pattern" value="%nopexception${p_tim}\t${p_thr}\t${p_lvl}\t${p_log}\t${p_mdc}\t${p_msg}\t${p_exc}\t${p_mak}\t%n"/>
<property name="logDir" value="/var/log/onap" />
<property name="debugDir" value="/var/log/onap" />
<property name="componentName" value="logdemonode"></property>
<property name="subComponentName" value="node"></property>
<property name="errorLogName" value="error" />
<property name="metricsLogName" value="metrics" />
<property name="auditLogName" value="audit" />
<property name="debugLogName" value="debug" />
<property name="errorPattern" value="%d{"yyyy-MM-dd'T'HH:mm:ss.SSSXXX", UTC}|%X{RequestId}|%thread|%X{ServiceName}|%X{PartnerName}|%X{TargetEntity}|%X{TargetServiceName}|%.-5level|%X{ErrorCode}|%X{ErrorDesc}|%msg%n\t${p_mdc}\t${p_msg}\t${p_exc}\t${p_mak}\t%n" />
<property name="debugPattern" value="%d{"yyyy-MM-dd'T'HH:mm:ss.SSSXXX", UTC}|%X{RequestId}|%msg%n\t${p_mdc}\t${p_msg}\t${p_exc}\t${p_mak}\t%n" />
<property name="auditPattern" value="%X{BeginTimestamp}|%X{EndTimestamp}|%X{RequestId}|%X{ServiceInstanceId}|%thread||%X{ServiceName}|%X{PartnerName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDesc}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{Timer}|%X{ServerFQDN}|%X{RemoteHost}||||||||%msg%n" />
<property name="metricPattern" value="%X{BeginTimestamp}|%X{EndTimestamp}|%X{RequestId}|%X{ServiceInstanceId}|%thread||%X{ServiceName}|%X{PartnerName}|%X{TargetEntity}|%X{TargetServiceName}|%X{StatusCode}|%X{ResponseCode}|%X{ResponseDesc}|%X{InstanceUUID}|%.-5level|%X{AlertSeverity}|%X{ServerIPAddress}|%X{Timer}|%X{ServerFQDN}|%X{RemoteHost}||||%X{TargetVirtualEntity}|||||%msg%n" />
<property name="logDirectory" value="${logDir}/${componentName}/${subComponentName}" />
<property name="debugLogDirectory" value="${debugDir}/${componentName}/${subComponentName}" />
<appender name="EELFAudit"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${logDirectory}/${auditLogName}.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${logDirectory}/${auditLogName}.log.%d</fileNamePattern>
</rollingPolicy>
<encoder>
<pattern>${auditPattern}</pattern>
</encoder>
</appender>
<appender name="asyncEELFAudit" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize>
<appender-ref ref="EELFAudit" />
</appender>
<appender name="EELFMetrics" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${logDirectory}/${metricsLogName}.log</file>
<rollingPolicy
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${logDirectory}/${metricsLogName}.log.%d</fileNamePattern>
</rollingPolicy>
<encoder>
<pattern>${metricPattern}</pattern>
</encoder>
</appender>
<appender name="asyncEELFMetrics" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize>
<appender-ref ref="EELFMetrics"/>
</appender>
<appender name="EELFError"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${logDirectory}/${errorLogName}.log</file>
<rollingPolicy
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${logDirectory}/${errorLogName}.log.%d</fileNamePattern>
</rollingPolicy>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<encoder>
<pattern>${errorPattern}</pattern>
</encoder>
</appender>
<appender name="asyncEELFError" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize>
<appender-ref ref="EELFError"/>
</appender>
<appender name="EELFDebug"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${debugLogDirectory}/${debugLogName}.log</file>
<rollingPolicy
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${debugLogDirectory}/${debugLogName}.log.%d</fileNamePattern>
</rollingPolicy>
<encoder>
<pattern>${debugPattern}</pattern>
</encoder>
</appender>
<appender name="asyncEELFDebug" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>256</queueSize>
<appender-ref ref="EELFDebug" />
<includeCallerData>true</includeCallerData>
</appender>
<logger name="com.att.eelf.audit" level="info" additivity="false">
<appender-ref ref="asyncEELFAudit" />
</logger>
<logger name="com.att.eelf.metrics" level="info" additivity="false">
<appender-ref ref="asyncEELFMetrics" />
</logger>
<logger name="com.att.eelf.error" level="debug" additivity="false">
<appender-ref ref="asyncEELFError" />
</logger>
<root level="INFO">
<appender-ref ref="asyncEELFDebug" />
</root>
</configuration> |
spring.xml
Code Block | ||||
---|---|---|---|---|
| ||||
<aop:aspectj-autoproxy />
<beans>
<bean class="org.onap.demo.logging.LoggingAspect" /> <!-- required even though we annotate with @Aspect -->
</beans> |
pom.xml
Add the following
Code Block | ||||
---|---|---|---|---|
| ||||
<logback.version>1.2.3</logback.version>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>${logback.version}</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>${logback.version}</version>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-aop</artifactId>
<version>${spring.version}</version>
</dependency>
# add the logging library pom (soon to be 1.2.2)
<dependency>
<groupId>org.onap.logging-analytics</groupId>
<artifactId>logging-slf4j</artifactId>
<version>1.2.0-SNAPSHOT</version>
</dependency> |
Logging With AOP
Jira | ||||||
---|---|---|---|---|---|---|
|
Class under Test
Prototyped AOP advice around Luke's library - minimal client changes - just an aspect bean and annotations required
Code Block | ||||
---|---|---|---|---|
| ||||
import javax.servlet.http.HttpServletRequest;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;
@Service("daoFacade")
public class ApplicationService implements ApplicationServiceLocal {
@Override
public Boolean health(HttpServletRequest servletRequest) {
Boolean health = true;
// TODO: check database
// Log outside the AOP framework - to simulate existing component logs between the ENTRY/EXIT markers
LoggerFactory.getLogger(this.getClass()).info("Running /health");
return health;
}
} |
Aspect References
Code Block | ||||
---|---|---|---|---|
| ||||
package org.onap.demo.logging;
import javax.servlet.http.HttpServletRequest;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.onap.logging.ref.slf4j.ONAPLogAdapter;
import org.slf4j.LoggerFactory;
@Aspect
public class LoggingAspect {
@Before("execution(* org.onap.demo.logging.*.*(..))")
public void logBefore(JoinPoint joinPoint) {
Object[] args = joinPoint.getArgs();
Object servletRequest = args[0];
ONAPLogAdapter.HttpServletRequestAdapter requestAdapter =
new ONAPLogAdapter.HttpServletRequestAdapter((HttpServletRequest)servletRequest);
final ONAPLogAdapter adapter = new ONAPLogAdapter(
LoggerFactory.getLogger(joinPoint.getTarget().getClass()));
try {
adapter.entering(requestAdapter);
} finally {
}
}
@After("execution(* org.onap.demo.logging.*.*(..))")
public void logAfter(JoinPoint joinPoint) {
final ONAPLogAdapter adapter = new ONAPLogAdapter(
LoggerFactory.getLogger(joinPoint.getTarget().getClass()));
adapter.exiting();
}
|
Logging Results
Use Case: Single REST call - with ENTRY/EXIT Markers around in-method log
Code Block | ||||
---|---|---|---|---|
| ||||
results - still working on passing in the servlet request
INFO: Reloading Context with name [/logging-demo] is completed
2018-07-09T14:48:01.014Z http-nio-8080-exec-8 INFO org.onap.demo.logging.ApplicationService
InstanceUUID=67bc4b12-56a1-4b62-ab78-0c8ca8834383,
RequestID=023af35a-b281-49c4-bf13-5167b1453780,
ServiceName=/logging-demo/rest/health/health,
InvocationID=94dc9e24-3722-43e5-8995-12f95e153ca3,
InvokeTimestamp=2018-07-09T14:48:01.008Z,
PartnerName=,
ClientIPAddress=0:0:0:0:0:0:0:1,
ServerFQDN=localhost ENTRY
2018-07-09T14:48:01.014Z http-nio-8080-exec-8 INFO org.onap.demo.logging.ApplicationService
InstanceUUID=67bc4b12-56a1-4b62-ab78-0c8ca8834383,
RequestID=023af35a-b281-49c4-bf13-5167b1453780,
ServiceName=/logging-demo/rest/health/health,
InvocationID=94dc9e24-3722-43e5-8995-12f95e153ca3,
InvokeTimestamp=2018-07-09T14:48:01.008Z,
PartnerName=,
ClientIPAddress=0:0:0:0:0:0:0:1,
ServerFQDN=localhost Running /health
2018-07-09T14:48:01.015Z http-nio-8080-exec-8 INFO org.onap.demo.logging.ApplicationService
ResponseCode=,
InstanceUUID=67bc4b12-56a1-4b62-ab78-0c8ca8834383,
RequestID=023af35a-b281-49c4-bf13-5167b1453780,
ServiceName=/logging-demo/rest/health/health,
ResponseDescription=,
InvocationID=94dc9e24-3722-43e5-8995-12f95e153ca3,
Severity=,
InvokeTimestamp=2018-07-09T14:48:01.008Z,
PartnerName=,
ClientIPAddress=0:0:0:0:0:0:0:1,
ServerFQDN=localhost,
StatusCode= EXIT |
AOP Stacktrace - logBefore()
Code Block | ||||
---|---|---|---|---|
| ||||
Tomcat v8.5 Server at localhost [Apache Tomcat]
org.apache.catalina.startup.Bootstrap at localhost:51622
Daemon Thread [http-nio-8080-exec-1] (Suspended (breakpoint at line 41 in LoggingAspect))
owns: NioEndpoint$NioSocketWrapper (id=147)
LoggingAspect.logBefore(JoinPoint) line: 41
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 62
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 43
Method.invoke(Object, Object...) line: 498
AspectJMethodBeforeAdvice(AbstractAspectJAdvice).invokeAdviceMethodWithGivenArgs(Object[]) line: 629
AspectJMethodBeforeAdvice(AbstractAspectJAdvice).invokeAdviceMethod(JoinPointMatch, Object, Throwable) line: 611
AspectJMethodBeforeAdvice.before(Method, Object[], Object) line: 43
MethodBeforeAdviceInterceptor.invoke(MethodInvocation) line: 51
JdkDynamicAopProxy.invoke(Object, Method, Object[]) line: 213
$Proxy51.health(HttpServletRequest) line: not available
RestHealthServiceImpl.getHealth() line: 48
ServerRuntime$2.run() line: 326
WebComponent.service(URI, URI, HttpServletRequest, HttpServletResponse) line: 427
ServletContainer.service(URI, URI, HttpServletRequest, HttpServletResponse) line: 388
|
Deploying demo pod
Helm Deployment
Code Block | ||
---|---|---|
| ||
# prereq
- Makefile in k8s root - copied/modified-parent-chart from https://git.onap.org/oom/tree/kubernetes/Makefile
- oom and logging-analytics cloned
sudo git clone https://gerrit.onap.org/r/oom
sudo git clone https://gerrit.onap.org/r/logging-analytics
cd logging-analytics
# pull patch in progress
sudo git pull https://gerrit.onap.org/r/logging-analytics refs/changes/71/57171/9
# install onap log
/oom/kubernetes$ sudo helm delete --purge onap
/oom/kubernetes$ sudo make all
/oom/kubernetes$ sudo make onap
/oom/kubernetes$ sudo helm install local/onap -n onap --namespace onap -f onap/resources/environments/disable-allcharts.yaml --set log.enabled=false
/oom/kubernetes$ sudo helm upgrade -i onap local/onap --namespace onap -f onap/resources/environments/disable-allcharts.yaml --set log.enabled=true
# install logdemo
/logging-analytics/reference/logging-kubernetes$ sudo helm delete --purge logdemonode
/logging-analytics/reference/logging-kubernetes$ sudo make all
/logging-analytics/reference/logging-kubernetes$ sudo make logdemonode
/logging-analytics/reference/logging-kubernetes$ sudo helm install local/logdemonode -n logdemonode --namespace onap --set logdemonode.enabled=true
# rebuild after code change
/logging-analytics/reference/logging-kubernetes$ sudo helm upgrade -i logdemonode local/logdemonode --namespace onap --set logdemonode.enabled=false
# results
onap logdemonode-logdemonode-5c8bffb468-rx2br 2/2 Running 0 1m
onap onap-log-elasticsearch-7557486bc4-9h7gf 1/1 Running 0 40m
onap onap-log-kibana-fc88b6b79-rkpzx 1/1 Running 0 40m
onap onap-log-logstash-fpzc5 1/1 Running 0 40m
onap log-es NodePort 10.43.17.89 <none> 9200:30254/TCP 39m
onap log-es-tcp ClusterIP 10.43.120.133 <none> 9300/TCP 39m
onap log-kibana NodePort 10.43.73.68 <none> 5601:30253/TCP 39m
onap log-ls NodePort 10.43.107.55 <none> 5044:30255/TCP 39m
onap log-ls-http ClusterIP 10.43.48.177 <none> 9600/TCP 39m
onap logdemonode NodePort 10.43.0.35 <none> 8080:30258/TCP 55s
ubuntu@ip-172-31-54-73:~$ curl http://dev.onap.info:30258/logging-demo/rest/health/health
true
# check records in elasticsearch
ubuntu@ip-172-31-54-73:~$ curl http://dev.onap.info:30254/_search?q=*
{"took":3,"timed_out":false,"_shards":{"total":21,"successful":21,"failed":0},"hits":{"total":2385953,"max_score":1.0,"hits":[{"_index":".kibana","_type":"index-pattern","_id":"logstash-*","_score":1.0,"_source":{"title":"logstash-*","timeFieldName":"@timestamp","notExpandable":true,"fields":"[{\"name\":\"@timestamp\",\"type\":\"date\",\"count\":0,\ |
FAQ / Workarounds
Issue: Logs not appearing in the ELK stack
Check that your volumeMounts are correct in both your application container and filebeat container - for example there must be a /var/log/onap in both
Code Block | ||||
---|---|---|---|---|
| ||||
volumeMounts:
- name: {{ include "common.fullname" . }}-logs
mountPath: /var/log/onap |
Issue: DNS error pushing logs from filebeat to logstash
Check that your config section in values.yaml either at the helm root or subchart level define the service name and port
Code Block | ||||
---|---|---|---|---|
| ||||
config:
logstashServiceName: log-ls
logstashPort: 5044 |
Design Issues
DI 8: Log Collection
Currently log collection occurs via the filebeat sidecar container. There is 1 container per pod that pushes logs from the emptydir PV volume to logstash.
DI 8: LOG-587: Refactoring filebeat to run as a per VM DaemonSet deployment
There is an optimization that can be prototyped where we instead push logs directly from each cluster VM right from the kubelet logs containing the PV's for each container on that VM - via a DaemonSet filebeat container (1 per VM instead of 1 per microservice)
The logstash container was recently changed to a DaemonSet deployment - use this as a chart reference
Example of where logs are put for the emptyDir PV
Code Block | ||
---|---|---|
| ||
ubuntu@ip-172-31-55-235:~/_dev/20180712-log-137/oom/kubernetes$ sudo ls /var/lib/kubelet/pods/b3f9e7bc-8d79-11e8-969d-02a1d5a57c25/volumes/kubernetes.io~empty-dir/onap-logdemonode-logs/logdemonode/node -la
-rw-r--r-- 1 root root 0 Jul 22 06:37 audit.log
-rw-r--r-- 1 root root 548 Jul 22 07:01 debug.log
-rw-r--r-- 1 root root 0 Jul 22 06:37 error.log
-rw-r--r-- 1 root root 0 Jul 22 06:37 metrics.log |
under the following
Jira | ||||||
---|---|---|---|---|---|---|
|
Logstash is already a DaemonSet – you can use that as the deployment part of the example (small change) – the larger piece will be to point filebeat to a subset of the emptyDir PV directory or target individual pod PVs on that VM for log shipping.
for example you will need to correlate the PV UUID on the VM with the kubernetes deployment pod id to map the correct pod to it’s emptyDir pv – or just push everything appearing in the kubelet dir.
I am hoping that a switch of the service to a DaemonSet – a one line change and blind pushing of all or a subset (minus the kubernetes/rancher/Grafana pods) of the volumes/kubernetes.io~empty-dir would be sufficient.
https://lists.onap.org/g/onap-discuss/topic/understanding_daemonset_in/24142759?p=,,,20,0,0,0::recentpostdate%2Fsticky,,,20,2,0,24142759see separate page (cross releases) in Logging Developer Guide