Policy Executor: handle errors

- configurable default answer
- apply default answer upon non 2xx response
- delayed default webclient read timeout
- add custom timeout method with original read timeout in seconds
- apply default answer upon timeout
- add integration test with short timeout error scenario

Issue-ID: CPS-2412
Change-Id: I62527a27e426c2f01fda2182ebd2513242c29ac1
Signed-off-by: ToineSiebelink <toine.siebelink@est.tech>

6 files changed, 121 insertions, 37 deletions

diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfig.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfig.java
index 0903c671b5..30e7cd5e0b 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfig.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfig.java
@@ -20,6 +20,7 @@
 
 package org.onap.cps.ncmp.config;
 
+import jakarta.annotation.PostConstruct;
 import lombok.Getter;
 import lombok.Setter;
 import org.springframework.boot.context.properties.ConfigurationProperties;
@@ -38,4 +39,9 @@ public class PolicyExecutorHttpClientConfig {
     public static class AllServices extends ServiceConfig {
         private String connectionProviderName = "policyExecutorConfig";
     }
+
+    @PostConstruct
+    public void increaseReadTimeoutOfWebClient() {
+        allServices.setReadTimeoutInSeconds(allServices.getReadTimeoutInSeconds() + 10);
+    }
 }
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutor.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutor.java
index 96771e30f1..caed28a648 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutor.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutor.java
@@ -23,16 +23,18 @@ package org.onap.cps.ncmp.impl.data.policyexecutor;
 import com.fasterxml.jackson.core.JsonProcessingException;
 import com.fasterxml.jackson.databind.JsonNode;
 import com.fasterxml.jackson.databind.ObjectMapper;
+import java.time.Duration;
+import java.time.temporal.ChronoUnit;
 import java.util.Collections;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.concurrent.TimeoutException;
 import lombok.RequiredArgsConstructor;
 import lombok.extern.slf4j.Slf4j;
 import org.onap.cps.ncmp.api.data.models.OperationType;
 import org.onap.cps.ncmp.api.exceptions.NcmpException;
 import org.onap.cps.ncmp.api.exceptions.PolicyExecutorException;
-import org.onap.cps.ncmp.api.exceptions.ServerNcmpException;
 import org.onap.cps.ncmp.impl.inventory.models.YangModelCmHandle;
 import org.onap.cps.ncmp.impl.utils.http.RestServiceUrlTemplateBuilder;
 import org.onap.cps.ncmp.impl.utils.http.UrlTemplateParameters;
@@ -52,12 +54,18 @@ public class PolicyExecutor {
     @Value("${ncmp.policy-executor.enabled:false}")
     private boolean enabled;
 
+    @Value("${ncmp.policy-executor.defaultDecision:deny}")
+    private String defaultDecision;
+
     @Value("${ncmp.policy-executor.server.address:http://policy-executor}")
     private String serverAddress;
 
     @Value("${ncmp.policy-executor.server.port:8080}")
     private String serverPort;
 
+    @Value("${ncmp.policy-executor.httpclient.all-services.readTimeoutInSeconds:30}")
+    private long readTimeoutInSeconds;
+
     @Qualifier("policyExecutorWebClient")
     private final WebClient policyExecutorWebClient;
 
@@ -80,26 +88,26 @@ public class PolicyExecutor {
                                 final String changeRequestAsJson) {
         log.trace("Policy Executor Enabled: {}", enabled);
         if (enabled) {
-            final ResponseEntity<JsonNode> responseEntity =
-                getPolicyExecutorResponse(yangModelCmHandle, operationType, authorization, resourceIdentifier,
-                    changeRequestAsJson);
-
+            ResponseEntity<JsonNode> responseEntity = null;
+            try {
+                responseEntity =
+                    getPolicyExecutorResponse(yangModelCmHandle, operationType, authorization, resourceIdentifier,
+                        changeRequestAsJson);
+            } catch (final RuntimeException runtimeException) {
+                processException(runtimeException);
+            }
             if (responseEntity == null) {
-                log.warn("No valid response from policy, ignored");
+                log.warn("No valid response from Policy Executor, ignored");
                 return;
             }
-
             if (responseEntity.getStatusCode().is2xxSuccessful()) {
                 if (responseEntity.getBody() == null) {
-                    log.warn("No valid response body from policy, ignored");
+                    log.warn("No valid response body from Policy Executor, ignored");
                     return;
                 }
-                processResponse(responseEntity.getBody());
+                processSuccessResponse(responseEntity.getBody());
             } else {
-                log.warn("Policy Executor invocation failed with status {}",
-                    responseEntity.getStatusCode().value());
-                throw new ServerNcmpException("Policy Executor invocation failed", "HTTP status code: "
-                    + responseEntity.getStatusCode().value());
+                processNon2xxResponse(responseEntity.getStatusCode().value());
             }
         }
     }
@@ -143,8 +151,6 @@ public class PolicyExecutor {
                                                                final String authorization,
                                                                final String resourceIdentifier,
                                                                final String changeRequestAsJson) {
-
-
         final Map<String, Object> requestAsMap = getSingleRequestAsMap(yangModelCmHandle,
             operationType,
             resourceIdentifier,
@@ -163,21 +169,46 @@ public class PolicyExecutor {
             .body(BodyInserters.fromValue(bodyAsObject))
             .retrieve()
             .toEntity(JsonNode.class)
+            .timeout(Duration.of(readTimeoutInSeconds, ChronoUnit.SECONDS))
             .block();
     }
 
-    private static void processResponse(final JsonNode responseBody) {
+    private void processNon2xxResponse(final int httpStatusCode) {
+        processFallbackResponse("Policy Executor returned HTTP Status code " + httpStatusCode + ".");
+    }
+
+    private void processException(final RuntimeException runtimeException) {
+        if (runtimeException.getCause() instanceof TimeoutException) {
+            processFallbackResponse("Policy Executor request timed out.");
+        } else {
+            log.warn("Request to Policy Executor failed with unexpected exception", runtimeException);
+            throw runtimeException;
+        }
+    }
+
+    private void processFallbackResponse(final String message) {
+        final String decisionId = "N/A";
+        final String decision = defaultDecision;
+        final String warning = message + " Falling back to configured default decision: " + defaultDecision;
+        log.warn(warning);
+        processDecision(decisionId, decision, warning);
+    }
+
+    private static void processSuccessResponse(final JsonNode responseBody) {
         final String decisionId = responseBody.path("decisionId").asText("unknown id");
-        log.trace("Policy Executor Decision ID: {} ", decisionId);
         final String decision = responseBody.path("decision").asText("unknown");
+        final String messageFromPolicyExecutor = responseBody.path("message").asText();
+        processDecision(decisionId, decision, messageFromPolicyExecutor);
+    }
+
+    private static void processDecision(final String decisionId, final String decision, final String details) {
+        log.trace("Policy Executor decision id: {} ", decisionId);
         if ("allow".equals(decision)) {
-            log.trace("Policy Executor allows the operation");
+            log.trace("Operation allowed.");
         } else {
             log.warn("Policy Executor decision: {}", decision);
-            final String details = responseBody.path("message").asText();
             log.warn("Policy Executor message: {}", details);
-            final String message = "Policy Executor did not allow request. Decision #"
-                + decisionId + " : " + decision;
+            final String message = "Operation not allowed. Decision id " + decisionId + " : " + decision;
             throw new PolicyExecutorException(message, details);
         }
     }
diff --git a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfigSpec.groovy b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfigSpec.groovy
index ca71c345c1..b988f9e171 100644
--- a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfigSpec.groovy
+++ b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/config/PolicyExecutorHttpClientConfigSpec.groovy
@@ -41,8 +41,13 @@ class PolicyExecutorHttpClientConfigSpec extends Specification {
                 assert maximumConnectionsTotal == 32
                 assert pendingAcquireMaxCount == 33
                 assert connectionTimeoutInSeconds == 34
-                assert readTimeoutInSeconds == 35
                 assert writeTimeoutInSeconds == 36
             }
     }
+
+    def 'Increased read timeout.'() {
+        expect: 'Read timeout is 10 seconds more then configured to enable a separate timeout method in policy executor with the required timeout'
+            assert policyExecutorHttpClientConfig.allServices.readTimeoutInSeconds == 35 + 10
+
+    }
 }
diff --git a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorConfigurationSpec.groovy b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorConfigurationSpec.groovy
index c859bb0a09..960e6b32f3 100644
--- a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorConfigurationSpec.groovy
+++ b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorConfigurationSpec.groovy
@@ -39,7 +39,9 @@ class PolicyExecutorConfigurationSpec extends Specification {
     def 'Policy executor configuration properties.'() {
         expect: 'properties used from application.yml'
             assert objectUnderTest.enabled
+            assert objectUnderTest.defaultDecision == 'some default decision'
             assert objectUnderTest.serverAddress == 'http://localhost'
             assert objectUnderTest.serverPort == '8785'
+            assert objectUnderTest.readTimeoutInSeconds == 35
     }
 }
diff --git a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorSpec.groovy b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorSpec.groovy
index 63a915ab64..46c0ddeb93 100644
--- a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorSpec.groovy
+++ b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/data/policyexecutor/PolicyExecutorSpec.groovy
@@ -28,7 +28,6 @@ import com.fasterxml.jackson.databind.JsonNode
 import com.fasterxml.jackson.databind.ObjectMapper
 import org.onap.cps.ncmp.api.exceptions.NcmpException
 import org.onap.cps.ncmp.api.exceptions.PolicyExecutorException
-import org.onap.cps.ncmp.api.exceptions.ServerNcmpException
 import org.onap.cps.ncmp.impl.inventory.models.YangModelCmHandle
 import org.slf4j.LoggerFactory
 import org.springframework.http.HttpStatus
@@ -37,6 +36,8 @@ import org.springframework.web.reactive.function.client.WebClient
 import reactor.core.publisher.Mono
 import spock.lang.Specification
 
+import java.util.concurrent.TimeoutException
+
 import static org.onap.cps.ncmp.api.data.models.OperationType.CREATE
 import static org.onap.cps.ncmp.api.data.models.OperationType.DELETE
 import static org.onap.cps.ncmp.api.data.models.OperationType.PATCH
@@ -69,52 +70,90 @@ class PolicyExecutorSpec extends Specification {
         ((Logger) LoggerFactory.getLogger(PolicyExecutor)).detachAndStopAllAppenders()
     }
 
-    def 'Permission check with allow response.'() {
+    def 'Permission check with "allow" decision.'() {
         given: 'allow response'
             mockResponse([decision:'allow'], HttpStatus.OK)
         when: 'permission is checked for an operation'
             objectUnderTest.checkPermission(new YangModelCmHandle(), operationType, 'my credentials','my resource',someValidJson)
         then: 'system logs the operation is allowed'
-            assert getLogEntry(2) == 'Policy Executor allows the operation'
+            assert getLogEntry(2) == 'Operation allowed.'
         and: 'no exception occurs'
             noExceptionThrown()
         where: 'all write operations are tested'
             operationType << [ CREATE, DELETE, PATCH, UPDATE ]
     }
 
-    def 'Permission check with other response (not allowed).'() {
+    def 'Permission check with "other" decision (not allowed).'() {
         given: 'other response'
             mockResponse([decision:'other', decisionId:123, message:'I dont like Mondays' ], HttpStatus.OK)
         when: 'permission is checked for an operation'
             objectUnderTest.checkPermission(new YangModelCmHandle(), PATCH, 'my credentials','my resource',someValidJson)
         then: 'Policy Executor exception is thrown'
             def thrownException = thrown(PolicyExecutorException)
-            assert thrownException.message == 'Policy Executor did not allow request. Decision #123 : other'
+            assert thrownException.message == 'Operation not allowed. Decision id 123 : other'
             assert thrownException.details == 'I dont like Mondays'
     }
 
-    def 'Permission check with non 2xx response.'() {
-        given: 'other response'
+    def 'Permission check with non-2xx response and "allow" default decision.'() {
+        given: 'other http response'
             mockResponse([], HttpStatus.I_AM_A_TEAPOT)
+        and: 'the configured default decision is "allow"'
+            objectUnderTest.defaultDecision = 'allow'
         when: 'permission is checked for an operation'
             objectUnderTest.checkPermission(new YangModelCmHandle(), PATCH, 'my credentials','my resource',someValidJson)
-        then: 'Server Ncmp exception is thrown'
-            def thrownException = thrown(ServerNcmpException)
-            assert thrownException.message == 'Policy Executor invocation failed'
-            assert thrownException.details == 'HTTP status code: 418'
+        then: 'No exception is thrown'
+            noExceptionThrown()
+    }
+
+    def 'Permission check with non-2xx response and "other" default decision.'() {
+        given: 'other http response'
+            mockResponse([], HttpStatus.I_AM_A_TEAPOT)
+        and: 'the configured default decision is NOT "allow"'
+            objectUnderTest.defaultDecision = 'deny by default'
+        when: 'permission is checked for an operation'
+            objectUnderTest.checkPermission(new YangModelCmHandle(), PATCH, 'my credentials', 'my resource', someValidJson)
+        then: 'Policy Executor exception is thrown'
+            def thrownException = thrown(PolicyExecutorException)
+            assert thrownException.message == 'Operation not allowed. Decision id N/A : deny by default'
+            assert thrownException.details == 'Policy Executor returned HTTP Status code 418. Falling back to configured default decision: deny by default'
     }
 
     def 'Permission check with invalid response from Policy Executor.'() {
         given: 'invalid response from Policy executor'
             mockResponseSpec.toEntity(*_) >> invalidResponse
         when: 'permission is checked for an operation'
-            objectUnderTest.checkPermission(new YangModelCmHandle(), CREATE, 'my credentials','my resource',someValidJson)
+            objectUnderTest.checkPermission(new YangModelCmHandle(), CREATE, 'my credentials', 'my resource', someValidJson)
         then: 'system logs the expected message'
             assert getLogEntry(1) == expectedMessage
         where: 'following invalid responses are received'
-            invalidResponse                                        || expectedMessage
-            Mono.empty()                                           || 'No valid response from policy, ignored'
-            Mono.just(new ResponseEntity<>(null, HttpStatus.OK))   || 'No valid response body from policy, ignored'
+            invalidResponse                                      || expectedMessage
+            Mono.empty()                                         || 'No valid response from Policy Executor, ignored'
+            Mono.just(new ResponseEntity<>(null, HttpStatus.OK)) || 'No valid response body from Policy Executor, ignored'
+    }
+
+    def 'Permission check with timeout exception.'() {
+        given: 'a timeout during the request'
+            def cause = new TimeoutException()
+            mockResponseSpec.toEntity(*_) >> { throw new RuntimeException(cause) }
+        and: 'the configured default decision is NOT "allow"'
+            objectUnderTest.defaultDecision = 'deny by default'
+        when: 'permission is checked for an operation'
+            objectUnderTest.checkPermission(new YangModelCmHandle(), CREATE, 'my credentials', 'my resource', someValidJson)
+        then: 'Policy Executor exception is thrown'
+            def thrownException = thrown(PolicyExecutorException)
+            assert thrownException.message == 'Operation not allowed. Decision id N/A : deny by default'
+            assert thrownException.details == 'Policy Executor request timed out. Falling back to configured default decision: deny by default'
+    }
+
+    def 'Permission check with other runtime exception.'() {
+        given: 'some other runtime exception'
+            def originalException =  new RuntimeException()
+            mockResponseSpec.toEntity(*_) >> { throw originalException}
+        when: 'permission is checked for an operation'
+            objectUnderTest.checkPermission(new YangModelCmHandle(), CREATE, 'my credentials', 'my resource', someValidJson)
+        then: 'The original exception is thrown'
+            def thrownException = thrown(RuntimeException)
+            assert thrownException == originalException
     }
 
     def 'Permission check with an invalid change request json.'() {
diff --git a/cps-ncmp-service/src/test/resources/application.yml b/cps-ncmp-service/src/test/resources/application.yml
index c76831da74..df3375d5d0 100644
--- a/cps-ncmp-service/src/test/resources/application.yml
+++ b/cps-ncmp-service/src/test/resources/application.yml
@@ -83,6 +83,7 @@ ncmp:
 
     policy-executor:
         enabled: true
+        defaultDecision: "some default decision"
         server:
             address: http://localhost
             port: 8785