Versions Compared

Old Version 1

changes.mady.by.user Michael O'Brien

Saved on

compared with

New Version Current

changes.mady.by.user Michael O'Brien

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

Originally in the logging specification ONAP Application Logging Specification v1.2 (Casablanca) - but will be cross specification releases - so a separate guide.

...

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.

https://nexus.onap.org/service/local/repositories/snapshots/content/org/onap/logging-analytics/logging-library/

    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

...

Overall Logging and ELK Architecture

Log Locations and Volumes




Adding Filebeat to an ONAP Kubernetes POD

...

Helm Charts for Kubernetes

...



Python: pylog Library

https://lists.onap.org/g/onap-discuss/topic/logging_python_logging/25307286?p=,,,20,0,0,0::recentpostdate%2Fsticky,,,20,2,0,25307286

JAVA: Adding Logging to a WAR Project

Logback.xml

place in src/main/java/resources

...

Until then you can continue to use the same logback.xml used by other components that already log like portal/policy/aai/vid/clamp

https://gerrit.onap.org/r/#/c/62405

Code Block
languagejava
themeMidnight
linenumberstrue
#WIP#20180925


<configuration scan="false" debug="true">

      <!-- MDC and MARKER specific for Cassablanca -->
  <property name="p_timLogTimestamp"   value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, UTC}"/>

    <property name="p_lvlLevel"          value="%level%.-5level"/>

    <property name="p_log"Logger"         value="%logger"/>

    <property name="p_mdcMdc" value           value="%replace(%replace(%mdc){'\t','\\\\t'}){'\n', '\\\\n'}"/>

    <property name="p_msg"Message"        value="%replace(%replace(%msg){'\t', '\\\\t'}){'\n','\\\\n'}"/>

    <property name="p_excRootException"  value="%replace(%replace(%rootException){'\t', '\\\\t'}){'\n','\\\\n'}"/>

    <property name="p_makMarker"         value="%replace(%replace(%marker){'\t', '\\\\t'}){'\n','\\\\n'}"/>

    <property name="p_thrThread"         value="%thread"/>

  <!-- indexed  <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" />

-->
  <!--  for Casablanca we support both position dependent pipe delimited - and position independent KVP MDCs -->
  <property name="p_1_LogTimestamp"       value="${LogTimestamp}" />
  <property name="p_2_EntryTimestamp"     value="%X{EntryTimestamp}" />
  <property name="debugDirp_3_InvokeTimestamp"    value="/var/log/onap%X{InvokeTimestamp}" />

  <property name="componentName" value="logdemonode"></property>

  <property name="subComponentName" value="node"></property>

  <property name="errorLogName"p_4_RequestID"          value="error%X{RequestId}" />

  <property name="metricsLogNamep_5_InvocationID"       value="metrics%X{InvocationId}" />

  <property name="auditLogName" p_6_InstanceID"         value="audit%X{InstanceUUID}" />

 <!--  previously InstanceUUID -->
  <property name="debugLogNamep_7_ServiceInstanceID"  value="debug%X{ServiceInstanceId}" />

  <property name="errorPattern" p_8_thread"             value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, 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" />

${Thread}" />
  <property name="p_9_ServiceName"        value="%X{ServiceName}" />
  <property name="p_10_PartnerName"       value="%X{PartnerName}" />
  <property name="p_11_StatusCode"        value="%X{StatusCode}" />
  <property name="debugPatternp_12_ResponseCode"      value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, UTC}|%X{RequestId}|%msg%n\t${p_mdc}\t${p_msg}\t${p_exc}\t${p_mak}\t%n" />
%X{ResponseCode}" />
  <property name="p_13_ResponseDesc"      value="%X{ResponseDesc}" />
  <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" />

p_14_level"             value="${Level}" />
  <property name="p_15_Severity"          value="%X{Severity}" />
  <property name="p_16_ServerIPAddress"   value="%X{ServerIPAddress}" />
  <property name="metricPattern" p_17_ElapsedTime"       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" />

ElapsedTime}" />
  <property name="p_18_ServerFQDN"        value="%X{ServerFQDN}" />
  <property name="p_19_ClientIPAddress"   value="%X{ClientIPAddress}" />
  <property name="p_20_VirtualServerName" value="%X{VirtualServerName}" />
  <property name="p_21_ContextName"       value="%X{ContextName}" />
  <property name="p_22_TargetEntity"      value="%X{TargetEntity}" />
  <property name="logDirectoryp_23_TargetServiceName" value="$%X{logDirTargetServiceName}/${componentName}/${subComponentName}" /" />

  <property name="debugLogDirectory" p_24_TargetElement"     value="$%X{debugDir}/${componentName}/${subComponentName}TargetElement}" />

  <appender<property name="EELFAudit"

p_25_User"              classvalue="ch.qos.logback.core.rolling.RollingFileAppender">

    <file>${logDirectory}/${auditLogName}.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

%X{User}" />
  <property name="p_26_logger"            <fileNamePattern>${logDirectory}/value="${auditLogName}.log.%d</fileNamePattern>

    </rollingPolicy>

Logger}" />
  <property name="p_27_mdc"     <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>value="${Mdc}" />
  <property name="p_28_message"           value="${Message}" />
  <property name="p_29_marker"            value="${Marker}" />
  
  
  <property name="pattern" 
    value="%nopexception${p_1_LogTimestamp}|${p_2_EntryTimestamp}|${p_3_InvokeTimestamp}|${p_4_RequestID}|${p_5_InvocationID}|${p_6_InstanceID}|${p_7_ServiceInstanceID}|${p_8_thread}|${p_9_ServiceName}|${p_10_PartnerName}|${p_11_StatusCode}|${p_12_ResponseCode}|${p_13_ResponseDesc}|${p_14_level}|${p_15_Severity}|${p_16_ServerIPAddress}|${p_17_ElapsedTime}|${p_18_ServerFQDN}|${p_19_ClientIPAddress}|${p_20_VirtualServerName}|${p_21_ContextName}|${p_22_TargetEntity}|${p_23_TargetServiceName}|${p_24_TargetElement}|${p_25_User}|${p_26_logger}|${p_27_mdc}|${p_28_message}|${p_29_marker}%n" />

spring.xml

Code Block
languagexml
themeMidnight
<aop:aspectj-autoproxy />
<beans>
        <bean class="org.onap.demo.logging.LoggingAspect" /> <!-- required even though we annotate with @Aspect -->
</beans>

...

Code Block
languagejava
themeMidnight
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 Demo REST API 

Code Block
themeMidnight
curl http://dev.onap.info:30453/logging-demo/rest/health/health


Logging Results

Use Case: Single REST call - with ENTRY/EXIT Markers around in-method log

The key here is that you get logs for free - the entry/exit lines are generated - the line in the middle is from java application code

Code Block
languagexml
themeMidnight
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

...

Code Block
languagejava
themeMidnight
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

Image Removed

Deploying demo pod

...

Image Added

Deployment

Deploying demo pod

Helm Deployment

also as of 20180918 use Mike Elliott s plugin - https://gerrit.onap.org/r/#/c/67071/  at OOM Helm (un)Deploy plugins


Code Block
themeMidnight
# 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,\35      <none>        8080:30453/TCP   55s
ubuntu@ip-172-31-54-73:~$ curl http://dev.onap.info:30453/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,\


# note if PV's are left over (a helm 2.9.1 issue after an upgrade from Kubernetes 1.8 to 1.10 via Rancher 1.6.18 - add a delete namespace
sudo helm delete --purge onap
kubectl delete namespace onap
kubectl delete pv --all
kubectl delete pvc --all
kubectl delete secrets --all
kubectl delete clusterrolebindings --all


FAQ / Workarounds

Issue: Logs not appearing in the ELK stack

...

Code Block
languagexml
themeMidnight
config: 
  logstashServiceName: log-ls
  logstashPort: 5044

ELK Configuration

Logstash

Grok

Jira
serverONAP JIRA
serverId425b2b0a-557c-3c0c-b515-579789cceedb
keyLOG-490

ElasticSearch

Kibana

Design Issues

DI 8: Log Collection

...