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

2 files changed, 24 insertions, 3 deletions

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 b8bb64f537..e8ee600ea9 100644
--- 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 4d715d28c9..794bbc99d3 100644
--- 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'