2 files changed, 58 insertions, 26 deletions

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 b5fe0abaea..6956d85181 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
@@ -39,33 +39,47 @@ public class CpsLoggingAspectService {
 
     private static final String CPS_PACKAGE_NAME = "org.onap.cps";
     private static final String ALL_CPS_METHODS = "execution(* " + CPS_PACKAGE_NAME + "..*(..)))";
+    private static final String METHOD_RETURNING_SENSITIVE_DATA = "AuthPassword";
+    private static final String SENSITIVE_DATA_MASK = "***********";
 
     /**
-     * To measure method execution time as a logging.
+     * Intercept methods to measure and log execution details when debug level logging enabled.
      *
      * @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) {
+    public Object interceptMethodCall(final ProceedingJoinPoint proceedingJoinPoint) {
         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());
+
+            final Object logValue;
+            if (methodSignature.getName().contains(METHOD_RETURNING_SENSITIVE_DATA)) {
+                logValue = SENSITIVE_DATA_MASK;
+            } else {
+                logValue = returnValue;
+            }
+            logMethodCall(methodSignature, proceedingJoinPoint, stopWatch, logValue);
             return returnValue;
         }
         return proceedingJoinPoint.proceed();
     }
 
+    void logMethodCall(final MethodSignature methodSignature,
+                       final ProceedingJoinPoint proceedingJoinPoint,
+                       final StopWatch stopWatch,
+                       final Object logValue) {
+        log.debug("Execution time of : {}.{}() with argument[s] = {} having result = {} :: {} ms",
+                methodSignature.getDeclaringType().getSimpleName(),
+                methodSignature.getName(), Arrays.toString(proceedingJoinPoint.getArgs()), logValue,
+                stopWatch.getTotalTimeMillis());
+    }
+
     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 1308bd7297..d0e19ad8d4 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
@@ -22,34 +22,31 @@ package org.onap.cps.aop
 
 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")
+    private static final Logger logger = Logger.getLogger('org.onap.cps')
 
     def mockProceedingJoinPoint = Mock(ProceedingJoinPoint)
-    def mockMethodSignature = Mock(MethodSignature);
-    def objectUnderTest = new CpsLoggingAspectService()
+    def mockMethodSignature = Mock(MethodSignature)
+    def objectUnderTest = Spy(CpsLoggingAspectService)
 
     def setup() {
         mockMethodSignature.getDeclaringType() >> this.getClass()
-        mockMethodSignature.getDeclaringType().getSimpleName() >> 'CpsLoggingAspectServiceSpec'
-        mockMethodSignature.getName() >> 'logMethodExecutionTime'
         mockProceedingJoinPoint.getSignature() >> mockMethodSignature
     }
 
     def 'Log method execution time for log level : #logLevel.'() {
-        given: 'mock valid pointcut arguments and set log level to #logLevel'
-            mockProceedingJoinPoint.getArgs() >> 'dataspace-name'
+        given: 'normal method and log level of #logLevel'
+            mockMethodSignature.getName() >> 'some method'
             logger.setLevel(logLevel)
-        when: 'aop intercepts cps method'
-            objectUnderTest.logMethodExecutionTime(mockProceedingJoinPoint)
-        then: 'expected number of method execution'
-            expectedNumberOfMethodExecution * mockMethodSignature.getName()
+        when: 'cps method is intercepted'
+            objectUnderTest.interceptMethodCall(mockProceedingJoinPoint)
+        then: 'logging is only done for correct levels'
+            expectedNumberOfMethodExecution * objectUnderTest.logMethodCall(*_)
         where: 'the following log levels are used'
             logLevel     || expectedNumberOfMethodExecution
             Level.INFO   || 0
@@ -58,11 +55,32 @@ class CpsLoggingAspectServiceSpec extends Specification {
     }
 
     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: 'some exception is thrown'
-            thrown Exception
+        given: 'some exception is thrown'
+            def originalException = new Exception('some exception')
+            mockProceedingJoinPoint.proceed() >> {
+                throw originalException
+            }
+        when: 'cps method is intercepted'
+            objectUnderTest.interceptMethodCall(mockProceedingJoinPoint)
+        then: 'the same exception is still thrown'
+            def thrownException = thrown(Exception)
+            assert thrownException == originalException
     }
+
+    def 'Masking sensitive data.'() {
+        given: 'method named #methodName returns some value'
+            mockMethodSignature.getName() >> methodName
+            mockProceedingJoinPoint.proceed() >> 'original return value'
+        and: 'the logger level is set to FINE'
+            logger.setLevel(Level.FINE)
+        when: 'cps method is intercepted'
+           objectUnderTest.interceptMethodCall(mockProceedingJoinPoint)
+        then: 'the expected value is being logged'
+            1 * objectUnderTest.logMethodCall(_, _, _, expectedLogValue)
+        where: 'the following method names are used'
+            methodName        || expectedLogValue
+            'normalMethod'    || 'original return value'
+            'getAuthPassword' || '***********'
+    }
+
 }