Improve logging in NCMP
- Code to change to apply logs at runtime
- Fix for minor code smell
Issue-ID: CPS-855
Signed-off-by: sourabh_sourabh <sourabh.sourabh@est.tech>
Change-Id: I93a556fe0fb7ca05a42e84eb5ec4f84afaa8fd92
diff --git a/cps-ncmp-rest/src/main/java/org/onap/cps/ncmp/rest/exceptions/NetworkCmProxyRestExceptionHandler.java b/cps-ncmp-rest/src/main/java/org/onap/cps/ncmp/rest/exceptions/NetworkCmProxyRestExceptionHandler.java
index 8c6f9f1..d3450e5 100755
--- a/cps-ncmp-rest/src/main/java/org/onap/cps/ncmp/rest/exceptions/NetworkCmProxyRestExceptionHandler.java
+++ b/cps-ncmp-rest/src/main/java/org/onap/cps/ncmp/rest/exceptions/NetworkCmProxyRestExceptionHandler.java
@@ -20,6 +20,8 @@
package org.onap.cps.ncmp.rest.exceptions;
+import lombok.AccessLevel;
+import lombok.NoArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.onap.cps.ncmp.api.impl.exception.DmiRequestException;
import org.onap.cps.ncmp.api.impl.exception.NcmpException;
@@ -37,6 +39,7 @@
*/
@Slf4j
@RestControllerAdvice(assignableTypes = {NetworkCmProxyController.class})
+@NoArgsConstructor(access = AccessLevel.PACKAGE)
public class NetworkCmProxyRestExceptionHandler {
private static final String CHECK_LOGS_FOR_DETAILS = "Check logs for details.";
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/api/impl/NetworkCmProxyDataServiceImpl.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/api/impl/NetworkCmProxyDataServiceImpl.java
index 6a156b8..6b6e696 100755
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/api/impl/NetworkCmProxyDataServiceImpl.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/api/impl/NetworkCmProxyDataServiceImpl.java
@@ -176,8 +176,7 @@
}
}
- private void parseAndUpdateCmHandlesInDmiRegistration(final DmiPluginRegistration dmiPluginRegistration)
- throws JsonProcessingException {
+ private void parseAndUpdateCmHandlesInDmiRegistration(final DmiPluginRegistration dmiPluginRegistration) {
final PersistenceCmHandlesList updatedPersistenceCmHandlesList =
getUpdatedPersistenceCmHandlesList(dmiPluginRegistration, dmiPluginRegistration.getUpdatedCmHandles());
final String cmHandlesAsJson = jsonObjectMapper.asJsonString(updatedPersistenceCmHandlesList);
@@ -203,8 +202,7 @@
throw new DataValidationException(message, e.getMessage(), e);
}
- private void registerAndSyncNewCmHandles(final PersistenceCmHandlesList persistenceCmHandlesList)
- throws JsonProcessingException {
+ private void registerAndSyncNewCmHandles(final PersistenceCmHandlesList persistenceCmHandlesList) {
final String cmHandleJsonData = jsonObjectMapper.asJsonString(persistenceCmHandlesList);
cpsDataService.saveListElements(NCMP_DATASPACE_NAME, NCMP_DMI_REGISTRY_ANCHOR, "/dmi-registry",
cmHandleJsonData, NO_TIMESTAMP);
diff --git a/cps-rest/src/main/java/org/onap/cps/rest/exceptions/CpsRestExceptionHandler.java b/cps-rest/src/main/java/org/onap/cps/rest/exceptions/CpsRestExceptionHandler.java
index 52af81c..ceb5dc1 100755
--- a/cps-rest/src/main/java/org/onap/cps/rest/exceptions/CpsRestExceptionHandler.java
+++ b/cps-rest/src/main/java/org/onap/cps/rest/exceptions/CpsRestExceptionHandler.java
@@ -23,6 +23,8 @@
import javax.servlet.http.HttpServletRequest;
import javax.validation.ValidationException;
+import lombok.AccessLevel;
+import lombok.NoArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.onap.cps.rest.controller.AdminRestController;
import org.onap.cps.rest.controller.DataRestController;
@@ -46,6 +48,7 @@
@Slf4j
@RestControllerAdvice(assignableTypes = {AdminRestController.class, DataRestController.class,
QueryRestController.class})
+@NoArgsConstructor(access = AccessLevel.PACKAGE)
public class CpsRestExceptionHandler {
/**
diff --git a/cps-service/src/main/java/org/onap/cps/aop/CpsLoggingAspectService.java b/cps-service/src/main/java/org/onap/cps/aop/CpsLoggingAspectService.java
index 20c6af6..b5fe0ab 100644
--- a/cps-service/src/main/java/org/onap/cps/aop/CpsLoggingAspectService.java
+++ b/cps-service/src/main/java/org/onap/cps/aop/CpsLoggingAspectService.java
@@ -21,49 +21,53 @@
package org.onap.cps.aop;
import java.util.Arrays;
-import java.util.Optional;
+import java.util.logging.Level;
+import java.util.logging.Logger;
import lombok.SneakyThrows;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
-import org.springframework.boot.autoconfigure.condition.ConditionalOnExpression;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;
@Aspect
@Component
@Slf4j
-@ConditionalOnExpression(
- "'${logging.level.org.onap.cps}'.equalsIgnoreCase('DEBUG')"
-)
public class CpsLoggingAspectService {
- private static final String ALL_CPS_METHODS = "execution(* org.onap.cps..*(..)))";
+ private static final String CPS_PACKAGE_NAME = "org.onap.cps";
+ private static final String ALL_CPS_METHODS = "execution(* " + CPS_PACKAGE_NAME + "..*(..)))";
/**
* To measure method execution time as a logging.
+ *
* @param proceedingJoinPoint exposes the proceed(..) method in order to support around advice.
* @return empty in case of void otherwise an object of return type
*/
@Around(ALL_CPS_METHODS)
@SneakyThrows
public Object logMethodExecutionTime(final ProceedingJoinPoint proceedingJoinPoint) {
- final StopWatch stopWatch = new StopWatch();
+ if (isSlf4JDebugEnabled()) {
+ final StopWatch stopWatch = new StopWatch();
+ //Calculate method execution time
+ stopWatch.start();
+ final Object returnValue = proceedingJoinPoint.proceed();
+ stopWatch.stop();
+ final MethodSignature methodSignature = (MethodSignature) proceedingJoinPoint.getSignature();
+ //Log method execution time
+ log.debug("Execution time of : {}.{}() with argument[s] = {} having result = {} :: {} ms",
+ methodSignature.getDeclaringType().getSimpleName(),
+ methodSignature.getName(), Arrays.toString(proceedingJoinPoint.getArgs()), returnValue,
+ stopWatch.getTotalTimeMillis());
+ return returnValue;
+ }
+ return proceedingJoinPoint.proceed();
+ }
- //Calculate method execution time
- stopWatch.start();
- final Object logObject = Optional.ofNullable(proceedingJoinPoint.proceed()).orElse("");
- stopWatch.stop();
- final MethodSignature methodSignature = (MethodSignature) proceedingJoinPoint.getSignature();
- //Log method execution time
- log.debug("Execution time of : {}.{}() with argument[s] = {} having result = {} :: {} ms",
- methodSignature.getDeclaringType().getSimpleName(),
- methodSignature.getName(), Arrays.toString(proceedingJoinPoint.getArgs()), logObject,
- stopWatch.getTotalTimeMillis());
-
- return logObject;
+ private static boolean isSlf4JDebugEnabled() {
+ return Logger.getLogger(CPS_PACKAGE_NAME).isLoggable(Level.FINE);
}
}
diff --git a/cps-service/src/test/groovy/org/onap/cps/aop/CpsLoggingAspectServiceSpec.groovy b/cps-service/src/test/groovy/org/onap/cps/aop/CpsLoggingAspectServiceSpec.groovy
index b15af49..1308bd7 100644
--- a/cps-service/src/test/groovy/org/onap/cps/aop/CpsLoggingAspectServiceSpec.groovy
+++ b/cps-service/src/test/groovy/org/onap/cps/aop/CpsLoggingAspectServiceSpec.groovy
@@ -24,9 +24,13 @@
import org.aspectj.lang.reflect.MethodSignature
import org.onap.cps.spi.exceptions.DataValidationException
import spock.lang.Specification
+import java.util.logging.Level
+import java.util.logging.Logger
class CpsLoggingAspectServiceSpec extends Specification {
+ private static final Logger logger = Logger.getLogger("org.onap.cps")
+
def mockProceedingJoinPoint = Mock(ProceedingJoinPoint)
def mockMethodSignature = Mock(MethodSignature);
def objectUnderTest = new CpsLoggingAspectService()
@@ -38,24 +42,27 @@
mockProceedingJoinPoint.getSignature() >> mockMethodSignature
}
- def 'Log method execution time.'() {
- given: 'mock valid arguments'
+ def 'Log method execution time for log level : #logLevel.'() {
+ given: 'mock valid pointcut arguments and set log level to #logLevel'
mockProceedingJoinPoint.getArgs() >> 'dataspace-name'
- when: 'aop intercepts cps method and start calculation of time'
+ logger.setLevel(logLevel)
+ when: 'aop intercepts cps method'
objectUnderTest.logMethodExecutionTime(mockProceedingJoinPoint)
- then: 'process successfully and log details of executed method'
- 1 * mockProceedingJoinPoint.proceed()
+ then: 'expected number of method execution'
+ expectedNumberOfMethodExecution * mockMethodSignature.getName()
+ where: 'the following log levels are used'
+ logLevel || expectedNumberOfMethodExecution
+ Level.INFO || 0
+ Level.FINE || 1
+ Level.FINEST || 1
}
- def 'Creating a data validation exception for invalid args.'() {
- given: 'a data validation exception is created'
- mockProceedingJoinPoint.getArgs() >> {
- throw new DataValidationException('invalid args',
- 'invalid method arg(s) is passed', new Throwable())
- }
+ def 'Exception thrown during method execution.'() {
+ given: 'some exception is created'
+ mockProceedingJoinPoint.proceed() >> { throw new Exception("some exception") }
when: 'aop intercepts cps method and start calculation of time'
objectUnderTest.logMethodExecutionTime(mockProceedingJoinPoint)
- then: 'data validation exception is thrown'
- thrown(DataValidationException.class)
+ then: 'some exception is thrown'
+ thrown Exception
}
}