Fix failing CSIT and add unit test proving the bug

It was determined that one CSIT is intermittently failing due
to a CM-handle being deleted while module sync is in progress,
which causes the whole batch operation to fail. Even CM-handles
that did sync will not go into READY state, despite the logs
saying otherwise. This commit reproduces the issue in a unit test,
and prevents the issue in the CSIT by changing test order. Also,
errors during module sync tasks are reported at ERROR level.
(The actual bug fix will be addressed in another patch.)

Issue-ID: CPS-2474
Signed-off-by: danielhanrahan <daniel.hanrahan@est.tech>
Change-Id: I7e0d617cbd48d8fd1fad036079fbd876ee21d8a8

diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/AsyncTaskExecutor.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/AsyncTaskExecutor.java
index b8bb64f..e8ee600 100644 (file)
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/AsyncTaskExecutor.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/AsyncTaskExecutor.java
@@ -1,6 +1,6 @@
 /*
  *  ============LICENSE_START=======================================================
- *  Copyright (C) 2022-2023 Nordix Foundation
+ *  Copyright (C) 2022-2024 Nordix Foundation
  *  ================================================================================
  *  Licensed under the Apache License, Version 2.0 (the "License");
  *  you may not use this file except in compliance with the License.
@@ -68,9 +68,9 @@ public class AsyncTaskExecutor {
     private void handleTaskCompletion(final Object response, final Throwable throwable) {
         if (throwable != null) {
             if (throwable instanceof TimeoutException) {
-                log.warn("Async task didn't completed within the required time.");
+                log.error("Async task didn't completed within the required time.", throwable);
             } else {
-                log.debug("Watchdog async batch failed. caused by : {}", throwable.getMessage());
+                log.error("Watchdog async batch failed.", throwable);
             }
         }
     }

diff --git a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasksSpec.groovy b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasksSpec.groovy
index 4d715d2..794bbc9 100644 (file)
--- a/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasksSpec.groovy
+++ b/cps-ncmp-service/src/test/groovy/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasksSpec.groovy
@@ -34,6 +34,7 @@ import org.onap.cps.ncmp.impl.inventory.InventoryPersistence
 import org.onap.cps.ncmp.impl.inventory.models.CmHandleState
 import org.onap.cps.ncmp.impl.inventory.models.YangModelCmHandle
 import org.onap.cps.ncmp.impl.inventory.sync.lcm.LcmEventsCmHandleStateHandler
+import org.onap.cps.spi.exceptions.DataNodeNotFoundException
 import org.onap.cps.spi.model.DataNode
 import org.slf4j.LoggerFactory
 import spock.lang.Specification
@@ -121,6 +122,26 @@ class ModuleSyncTasksSpec extends Specification {
             'module upgrade' | MODULE_UPGRADE        | 'Upgrade in progress'                          || MODULE_UPGRADE_FAILED
     }
 
+    // TODO Update this test once the bug CPS-2474 is fixed
+    def 'Module sync fails if a handle gets deleted during module sync.'() {
+        given: 'cm handles in an ADVISED state'
+            def cmHandle1 = cmHandleAsDataNodeByIdAndState('cm-handle-1', CmHandleState.ADVISED)
+            def cmHandle2 = cmHandleAsDataNodeByIdAndState('cm-handle-2', CmHandleState.ADVISED)
+        and: 'inventory persistence returns the first handle with ADVISED state'
+            mockInventoryPersistence.getCmHandleState('cm-handle-1') >> new CompositeState(cmHandleState: CmHandleState.ADVISED)
+        and: 'inventory persistence cannot find the second handle'
+            mockInventoryPersistence.getCmHandleState('cm-handle-2') >> { throw new DataNodeNotFoundException('dataspace', 'anchor', 'xpath') }
+        when: 'module sync poll is executed'
+            objectUnderTest.performModuleSync([cmHandle1, cmHandle2], batchCount)
+        then: 'an exception is thrown'
+            thrown(DataNodeNotFoundException)
+        and: 'even though the existing cm-handle did sync'
+            1 * mockModuleSyncService.syncAndCreateSchemaSetAndAnchor(_) >> { args -> assert args[0].id == 'cm-handle-1' }
+        and: 'logs report the cm-handle is in READY state'
+            assert getLoggingEvent().formattedMessage == 'cm-handle-1 is now in READY state'
+        and: 'this is impossible as the state handler was not called at all'
+            0 * mockLcmEventsCmHandleStateHandler.updateCmHandleStateBatch(_)
+    }
 
     def 'Reset failed CM Handles #scenario.'() {
         given: 'cm handles in an locked state'

diff --git a/csit/tests/cps-model-sync/cps-model-sync.robot b/csit/tests/cps-model-sync/cps-model-sync.robot
index 514076f..b4e61b3 100644 (file)
--- a/csit/tests/cps-model-sync/cps-model-sync.robot
+++ b/csit/tests/cps-model-sync/cps-model-sync.robot
@@ -78,17 +78,6 @@ Get CM Handle details and confirm it has been updated.
            END
     END
 
-Delete cm handle
-    ${uri}=              Set Variable       ${ncmpInventoryBasePath}/v1/ch
-    ${headers}=          Create Dictionary  Content-Type=application/json   Authorization=${auth}
-    ${response}=         POST On Session    CPS_URL   ${uri}   headers=${headers}   data=${deletePayload}
-    Should Be Equal As Strings              ${response.status_code}   200
-
-Get cm handle details and confirm it has been deleted
-    ${uri}=              Set Variable       ${ncmpBasePath}/v1/ch/CmHandleForDelete
-    ${headers}=          Create Dictionary  Authorization=${auth}
-    ${response}=         GET On Session     CPS_URL   ${uri}   headers=${headers}   expected_status=404
-
 Check if ietfYang-PNFDemo is READY
     ${uri}=        Set Variable       ${ncmpBasePath}/v1/ch/ietfYang-PNFDemo
     ${headers}=    Create Dictionary  Authorization=${auth}
@@ -107,6 +96,17 @@ Get modules for registered data node
             END
     END
 
+Delete cm handle
+    ${uri}=              Set Variable       ${ncmpInventoryBasePath}/v1/ch
+    ${headers}=          Create Dictionary  Content-Type=application/json   Authorization=${auth}
+    ${response}=         POST On Session    CPS_URL   ${uri}   headers=${headers}   data=${deletePayload}
+    Should Be Equal As Strings              ${response.status_code}   200
+
+Get cm handle details and confirm it has been deleted
+    ${uri}=              Set Variable       ${ncmpBasePath}/v1/ch/CmHandleForDelete
+    ${headers}=          Create Dictionary  Authorization=${auth}
+    ${response}=         GET On Session     CPS_URL   ${uri}   headers=${headers}   expected_status=404
+
 *** Keywords ***
 
 Is CM Handle READY
@@ -125,4 +125,4 @@ Count Items In JSON Response
     [Arguments]    ${response}
     ${json_data}=    Evaluate    json.loads('${response.content.decode("utf-8")}')   json
     ${number_of_items}=    Get Length    ${json_data}
-    RETURN    ${number_of_items}
\ No newline at end of file
+    RETURN    ${number_of_items}