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

Code Block

language	java
theme	Midnight
linenumbers	true

<configuration>
    <property name="p_tim" value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, 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'}"/>
    # tabs
    <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"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>~/output.log</file>
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>
    <logger level="INFO" name="org.onap.logging.ref.slf4j" additivity="false">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="FILE" />
    </logger>
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

spring.xml

Code Block

language	xml
theme	Midnight

<aop:aspectj-autoproxy />
<beans># pending annotation level weaving of the library
import org.onap.logging.ref.slf4j.ONAPLogAdapter;
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
    	final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    	try {
    	    adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
    	} finally {
    	    adapter.exiting();
    	}
    	return health;
    }
MDC's are set for example


this	LogbackMDCAdapter  (id=282)	
	copyOnInheritThreadLocal	InheritableThreadLocal<T>  (id=284)	
	lastOperation	ThreadLocal<T>  (id=287)	
key	"ServerFQDN" (id=273)	
val	"localhost" (id=272)	


{InstanceUUID=aa2d5b18-e3c2-44d3-b3ae-8565113a81b9, RequestID=788cf6a6-8008-4b95-af3f-61d92d9cbb4e, ServiceName=, InvocationID=dade7e58-fa24-4b2d-84e8-d3e89af9e6e1, InvokeTimestamp=2018-07-05T14:25:05.739Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost}


in	
LogbackMDCAdapter.put(String, String) line: 98	
MDC.put(String, String) line: 147	
ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 327	
ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
ApplicationService.health(HttpServletRequest) line: 38	
RestHealthServiceImpl.getHealth() line: 47	

# fix
get() returned	"" (id=201)	
key	"ServiceName" (id=340)	

Daemon Thread [http-nio-8080-exec-12] (Suspended)	
	owns: NioEndpoint$NioSocketWrapper  (id=113)	
	MDC.get(String) line: 203	
	ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 336	
	ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
	ApplicationService.health(HttpServletRequest) line: 38	
	RestHealthServiceImpl.getHealth() line: 47	

        if (MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME) == null) {
            MDC.put(ONAPLogConstants.MDCs.SERVICE_NAME, request.getRequestURI());

to
        if (MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME) == null ||
                MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME).equalsIgnoreCase(EMPTY_MESSAGE)) {

In progress

Jira

server	ONAP JIRA
serverId	425b2b0a-557c-3c0c-b515-579789cceedb
key	LOG-552

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Run as "debug"/deploy to Tomcat via Eclipse - https://git.onap.org/logging-analytics/tree/reference/logging-demo

Exercise the health endpoint which invokes Luke Parker's logging library

http://localhost:8080/logging-demo/rest/health/health

Hit preset breakpoints - try

Code Block

language	java
theme	Midnight

this	ONAPLogAdapter  (id=130)	
	mLogger	Logger  (id=132)	
	mResponseDescriptor	ONAPLogAdapter$ResponseDescriptor  (id=138)	
	mServiceDescriptor	ONAPLogAdapter$ServiceDescriptor  (id=139)	
request	ONAPLogAdapter$HttpServletRequestAdapter  (id=131)	
requestID	"8367757d-59c2-4e3e-80cd-b2fdc7a114ea" (id=142)	
invocationID	"967e4fe8-84ea-40b0-b4b9-d5988348baec" (id=170)	
partnerName	"" (id=171)	


Tomcat v8.5 Server at localhost [Apache Tomcat]	
	org.apache.catalina.startup.Bootstrap at localhost:50485		
		Daemon Thread [http-nio-8080-exec-3] (Suspended)	
			owns: NioEndpoint$NioSocketWrapper  (id=104)	
			ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 312	
			ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
			ApplicationService.health(HttpServletRequest) line: 37	
			RestHealthServiceImpl.getHealth() line: 47	
			NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
...
			JavaResourceMethodDispatcherProvider$TypeOutInvoker(AbstractJavaResourceMethodDispatcher).invoke(ContainerRequest, Object, Object...) line: 161	
...
			ServletContainer.service(URI, URI, HttpServletRequest, HttpServletResponse) line: 388	
...	
			CoyoteAdapter.service(Request, Response) line: 342	
...
		Daemon Thread [http-nio-8080-exec-5] (Running)	
	/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/bin/java (Jul 4, 2018, 12:12:04 PM)	


output - note there are 3 tabs (see p_mak in logback.xml) delimiting the MARKERS (ENTRY and EXIT) at the end of each line
2018-07-05T20:21:34.794Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.ApplicationService	InstanceUUID=ede7dd52-91e8-45ce-9406-fbafd17a7d4c, RequestID=f9d8bb0f-4b4b-4700-9853-d3b79d861c5b, ServiceName=/logging-demo/rest/health/health, InvocationID=8f4c1f1d-5b32-4981-b658-e5992f28e6c8, InvokeTimestamp=2018-07-05T20:21:26.617Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost			ENTRY	
2018-07-05T20:22:09.268Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.ApplicationService	ResponseCode=, InstanceUUID=ede7dd52-91e8-45ce-9406-fbafd17a7d4c, RequestID=f9d8bb0f-4b4b-4700-9853-d3b79d861c5b, ServiceName=/logging-demo/rest/health/health, ResponseDescription=, InvocationID=8f4c1f1d-5b32-4981-b658-e5992f28e6c8, Severity=, InvokeTimestamp=2018-07-05T20:21:26.617Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost, StatusCode=			EXIT

Image Removed

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

Code Block

language	java
theme	Midnight
linenumbers	true

<configuration>
    <property name="p_tim" value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, 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'}"/>
    # tabs
    <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"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>~/output.log</file>
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>
    <logger level="INFO" name="org.onap.logging.ref.slf4j" additivity="false">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="FILE" />
    </logger>
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

spring.xml

Code Block

language	xml
theme	Midnight

<aop:aspectj-autoproxy />
<beans>
        <bean class="org.onap.demo.logging.LoggingAspect" />
</beans>

pom.xml

Add the following

Code Block

language	java
theme	Midnight

<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>

...

<bean class="org.onap.demo.logging.LoggingAspect" /> <!-- required even though we annotate with @Aspect -->
</beans>

pom.xml

Add the following

Code Block

language	java
theme	Midnight

<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>

With AOP

Class under Test

Prototyped AOP advice around Luke's library - minimal client changes - just an aspect bean and annotations required

Code Block

language	java
theme	Midnight

    @Override
    public Boolean health(HttpServletRequest servletRequest) {
    	Boolean health = true;
    	// TODO: check database
    	//LoggerFactory.getLogger(ApplicationService.class).info("Start /health");
    	//final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    	//try {
    	//    adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
    	//} finally {
    	//    adapter.exiting();
    	//}
    	return health;
    }

Aspect References

Code Block

language	java
theme	Midnight

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 {
    private final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    
    @Before("execution(* org.onap.demo.logging.*.*(..))")
    public void logBefore(JoinPoint joinPoint) {
        //final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
        LoggerFactory.getLogger(ApplicationService.class).info("Starting /health");
        try {
            //adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
        } finally {
            adapter.exiting();
        }
    }
}

results - still working on passing in the servlet request
2018-07-09T01:06:30.837Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.ApplicationService		Starting /health			
2018-07-09T01:06:30.841Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.LoggingAspect	ResponseCode=, ResponseDescription=, Severity=, StatusCode=			EXIT

Without Spring AOP

Code Block

language	java
theme	Midnight

# pending annotation level weaving of the library
import org.onap.logging.ref.slf4j.ONAPLogAdapter;
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
    	final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    	try {
    	    adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
    	} finally {
    	    adapter.exiting();
    	}
    	return health;
    }
MDC's are set for example


this	LogbackMDCAdapter  (id=282)	
	copyOnInheritThreadLocal	InheritableThreadLocal<T>  (id=284)	
	lastOperation	ThreadLocal<T>  (id=287)	
key	"ServerFQDN" (id=273)	
val	"localhost" (id=272)	


{InstanceUUID=aa2d5b18-e3c2-44d3-b3ae-8565113a81b9, RequestID=788cf6a6-8008-4b95-af3f-61d92d9cbb4e, ServiceName=, InvocationID=dade7e58-fa24-4b2d-84e8-d3e89af9e6e1, InvokeTimestamp=2018-07-05T14:25:05.739Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost}


in	
LogbackMDCAdapter.put(String, String) line: 98	
MDC.put(String, String) line: 147	
ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 327	
ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
ApplicationService.health(HttpServletRequest) line: 38	
RestHealthServiceImpl.getHealth() line: 47	

# fix
get() returned	"" (id=201)	
key	"ServiceName" (id=340)	

Daemon Thread [http-nio-8080-exec-12] (Suspended)	
	owns: NioEndpoint$NioSocketWrapper  (id=113)	
	MDC.get(String) line: 203	
	ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 336	
	ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
	ApplicationService.health(HttpServletRequest) line: 38	
	RestHealthServiceImpl.getHealth() line: 47	

        if (MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME) == null) {
            MDC.put(ONAPLogConstants.MDCs.SERVICE_NAME, request.getRequestURI());

to
        if (MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME) == null ||
                MDC.get(ONAPLogConstants.MDCs.SERVICE_NAME).equalsIgnoreCase(EMPTY_MESSAGE)) {

In progress

Jira

server	ONAP JIRA
serverId	425b2b0a-557c-3c0c-b515-579789cceedb
key	LOG-552

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Run as "debug"/deploy to Tomcat via Eclipse - https://git.onap.org/logging-analytics/tree/reference/logging-demo

Exercise the health endpoint which invokes Luke Parker's logging library

http://localhost:8080/logging-demo/rest/health/health

Hit preset breakpoints - try

Prototyped AOP advice around Luke's library - minimal client changes - just an aspect bean and annotations required

Code Block

language	java
theme	Midnight

    @Override
    public Boolean health(HttpServletRequest servletRequest) {
    	Boolean health = true;
    	// TODO: check database
    	//LoggerFactory.getLogger(ApplicationService.class).info("Start /health");
    	//final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    	//try {
    	//    adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
    	//} finally {
    	//    adapter.exiting();
    	//}
    	return health;
    }

...

Code Block

language	java
theme	Midnight

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 {
    private final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
    
    @Before("execution(* org.onap.demo.logging.*.*(..))")
    public void logBefore(JoinPoint joinPoint) {
        //final ONAPLogAdapter adapter = new ONAPLogAdapter(LoggerFactory.getLogger(this.getClass()));
        LoggerFactory.getLogger(ApplicationService.class).info("Starting /health");
        try {
            //adapter.entering(new ONAPLogAdapter.HttpServletRequestAdapter(servletRequest));
        } finally {
            adapter.exiting();
        }
    }
}

results - still working on passing in the servlet request
2018-07-09T01:06:30.837Zthis	ONAPLogAdapter  (id=130)	
	mLogger	Logger  (id=132)	
	mResponseDescriptor	ONAPLogAdapter$ResponseDescriptor  (id=138)	
	mServiceDescriptor	ONAPLogAdapter$ServiceDescriptor  (id=139)	
request	ONAPLogAdapter$HttpServletRequestAdapter  (id=131)	
requestID	"8367757d-59c2-4e3e-80cd-b2fdc7a114ea" (id=142)	
invocationID	"967e4fe8-84ea-40b0-b4b9-d5988348baec" (id=170)	
partnerName	"" (id=171)	


Tomcat v8.5 Server at localhost [Apache Tomcat]	
	org.apache.catalina.startup.Bootstrap at localhost:50485		
		Daemon Thread [http-nio-8080-exec-3] (Suspended)	
			owns: NioEndpoint$NioSocketWrapper  (id=104)	
			ONAPLogAdapter.setEnteringMDCs(RequestAdapter<?>) line: 312	
			ONAPLogAdapter.entering(ONAPLogAdapter$RequestAdapter) line: 156	
			ApplicationService.health(HttpServletRequest) line: 37	
			RestHealthServiceImpl.getHealth() line: 47	
			NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]	
...
			JavaResourceMethodDispatcherProvider$TypeOutInvoker(AbstractJavaResourceMethodDispatcher).invoke(ContainerRequest, Object, Object...) line: 161	
...
			ServletContainer.service(URI, URI, HttpServletRequest, HttpServletResponse) line: 388	
...	
			CoyoteAdapter.service(Request, Response) line: 342	
...
		Daemon Thread [http-nio-8080-exec-5] (Running)	
	/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/bin/java (Jul 4, 2018, 12:12:04 PM)	


output - note there are 3 tabs (see p_mak in logback.xml) delimiting the MARKERS (ENTRY and EXIT) at the end of each line
2018-07-05T20:21:34.794Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.ApplicationService		Starting /health			InstanceUUID=ede7dd52-91e8-45ce-9406-fbafd17a7d4c, RequestID=f9d8bb0f-4b4b-4700-9853-d3b79d861c5b, ServiceName=/logging-demo/rest/health/health, InvocationID=8f4c1f1d-5b32-4981-b658-e5992f28e6c8, InvokeTimestamp=2018-07-05T20:21:26.617Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost			ENTRY	
2018-07-09T0105T20:0622:3009.841Z268Z	http-nio-8080-exec-2	INFO	org.onap.demo.logging.LoggingAspectApplicationService	ResponseCode=, InstanceUUID=ede7dd52-91e8-45ce-9406-fbafd17a7d4c, RequestID=f9d8bb0f-4b4b-4700-9853-d3b79d861c5b, ServiceName=/logging-demo/rest/health/health, ResponseDescription=, InvocationID=8f4c1f1d-5b32-4981-b658-e5992f28e6c8, Severity=, InvokeTimestamp=2018-07-05T20:21:26.617Z, PartnerName=, ClientIPAddress=0:0:0:0:0:0:0:1, ServerFQDN=localhost, StatusCode=			EXIT

Image Added

Remote Docker container in Kubernetes deployment

...

Space shortcuts

Page tree

Versions Compared

Old Version 49

New Version 50

Key

Adding Logging to a WAR Project

Logback.xml

spring.xml

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Logback.xml

spring.xml

pom.xml

pom.xml

With AOP

Class under Test

Aspect References

Without Spring AOP

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Remote Docker container in Kubernetes deployment

Space shortcuts

Page tree

Page History

Versions Compared

Old Version 49

New Version 50

Key

Adding Logging to a WAR Project

Logback.xml

spring.xml

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Logback.xml

spring.xml

pom.xml

pom.xml

With AOP

Class under Test

Aspect References

Without Spring AOP

Developer Debugging

Local Tomcat via Eclipse/IntelliJ

Remote Docker container in Kubernetes deployment