Improve logging in NCMP 21/127021/5
authorsourabh_sourabh <sourabh.sourabh@est.tech>
Tue, 8 Feb 2022 17:32:27 +0000 (23:02 +0530)
committersourabh_sourabh <sourabh.sourabh@est.tech>
Mon, 14 Feb 2022 14:43:50 +0000 (20:13 +0530)
- 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

cps-ncmp-rest/src/main/java/org/onap/cps/ncmp/rest/exceptions/NetworkCmProxyRestExceptionHandler.java
cps-ncmp-service/src/main/java/org/onap/cps/ncmp/api/impl/NetworkCmProxyDataServiceImpl.java
cps-rest/src/main/java/org/onap/cps/rest/exceptions/CpsRestExceptionHandler.java
cps-service/src/main/java/org/onap/cps/aop/CpsLoggingAspectService.java
cps-service/src/test/groovy/org/onap/cps/aop/CpsLoggingAspectServiceSpec.groovy

index 8c6f9f1..d3450e5 100755 (executable)
@@ -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 @@ import org.springframework.web.bind.annotation.RestControllerAdvice;
  */
 @Slf4j
 @RestControllerAdvice(assignableTypes = {NetworkCmProxyController.class})
+@NoArgsConstructor(access = AccessLevel.PACKAGE)
 public class NetworkCmProxyRestExceptionHandler {
 
     private static final String CHECK_LOGS_FOR_DETAILS = "Check logs for details.";
index 6a156b8..6b6e696 100755 (executable)
@@ -176,8 +176,7 @@ public class NetworkCmProxyDataServiceImpl implements NetworkCmProxyDataService
         }
     }
 
-    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 @@ public class NetworkCmProxyDataServiceImpl implements NetworkCmProxyDataService
         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);
index 52af81c..ceb5dc1 100755 (executable)
@@ -23,6 +23,8 @@ package org.onap.cps.rest.exceptions;
 
 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 @@ import org.springframework.web.bind.annotation.RestControllerAdvice;
 @Slf4j
 @RestControllerAdvice(assignableTypes = {AdminRestController.class, DataRestController.class,
     QueryRestController.class})
+@NoArgsConstructor(access = AccessLevel.PACKAGE)
 public class CpsRestExceptionHandler {
 
     /**
index 20c6af6..b5fe0ab 100644 (file)
 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();
-
-        //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());
+        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();
+    }
 
-        return logObject;
+    private static boolean isSlf4JDebugEnabled() {
+        return Logger.getLogger(CPS_PACKAGE_NAME).isLoggable(Level.FINE);
     }
 
 }
index b15af49..1308bd7 100644 (file)
@@ -24,9 +24,13 @@ import org.aspectj.lang.ProceedingJoinPoint
 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 @@ class CpsLoggingAspectServiceSpec extends Specification {
         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
     }
 }