From: lukegleeson Date: Wed, 7 Sep 2022 13:21:36 +0000 (+0100) Subject: Fix security bug in logs X-Git-Tag: 3.1.2~4 X-Git-Url: https://gerrit.onap.org/r/gitweb?a=commitdiff_plain;ds=sidebyside;h=c9ec915d7d16b88f53493c85928d463d070df472;p=cps.git Fix security bug in logs When a method with signature containing "AuthPassword" is passed, the value returned is changed to *********** in logs e.g... Execution time of : DmiProperties.getAuthPassword() with argument[s] = *********** ... Legacy code cleaning also included Issue-ID: CPS-1226 Signed-off-by: lukegleeson Change-Id: Ic4914eae7e5ed6d361287413d17abfe50a3788ae --- 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 b5fe0abae..6956d8518 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 1308bd729..d0e19ad8d 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' || '***********' + } + } diff --git a/docs/release-notes.rst b/docs/release-notes.rst index aa09eee27..5d3aa9205 100755 --- a/docs/release-notes.rst +++ b/docs/release-notes.rst @@ -40,6 +40,13 @@ Bug Fixes --------- - None +Security Notes +-------------- + +*Fixed Security Issues* + + - `CPS-1226 `_ Security bug in the logs + Version: 3.1.0 ==============