[Module Sync] Log state changes after persistence

Currently, module sync will output messages such as:
  "cm-handle-1 is now in READY state"
before the state change is persisted to the DB. If an exception
occurs, the new state may not be persisted, which makes debugging
hard due to misleading log entries. This commit moves the logging to
the LCM state handler immediately after the change is persisted.

- Move logging of state changes to LcmEventsCmHandleStateHandler.
- Remove unused code in LcmEventsCmHandleStateHandler.
- Add tests of state change logging.
- Update the main test showing the bug to instead show expected
  behaviour, but disable test for now using @Ignore.

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

5 files changed, 13 insertions, 66 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 e8ee600ea9..80bc4ab69f 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
@@ -68,7 +68,7 @@ public class AsyncTaskExecutor {
     private void handleTaskCompletion(final Object response, final Throwable throwable) {
         if (throwable != null) {
             if (throwable instanceof TimeoutException) {
-                log.error("Async task didn't completed within the required time.", throwable);
+                log.error("Async task didn't complete within the required time.", throwable);
             } else {
                 log.error("Watchdog async batch failed.", throwable);
             }
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasks.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasks.java
index e627f8f894..80cdea8b7b 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasks.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/ModuleSyncTasks.java
@@ -84,7 +84,6 @@ public class ModuleSyncTasks {
                     setCmHandleStateLocked(yangModelCmHandle, compositeState.getLockReason());
                     cmHandelStatePerCmHandle.put(yangModelCmHandle, CmHandleState.LOCKED);
                 }
-                log.info("{} is now in {} state", cmHandleId, cmHandelStatePerCmHandle.get(yangModelCmHandle).name());
             }
             lcmEventsCmHandleStateHandler.updateCmHandleStateBatch(cmHandelStatePerCmHandle);
         } finally {
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandler.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandler.java
index 6cce153269..de3df6b9da 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandler.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandler.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.
@@ -32,14 +32,6 @@ import org.onap.cps.ncmp.impl.inventory.models.YangModelCmHandle;
 public interface LcmEventsCmHandleStateHandler {
 
     /**
-     * Updates the composite state of cmHandle based on cmHandleState.
-     *
-     * @param yangModelCmHandle   cm handle represented as yang model
-     * @param targetCmHandleState target cm handle state
-     */
-    void updateCmHandleState(final YangModelCmHandle yangModelCmHandle, final CmHandleState targetCmHandleState);
-
-    /**
      * Updates the composite state of cmHandle based on cmHandleState in batch.
      *
      * @param cmHandleStatePerCmHandle Map of Yang Model Cm Handle and corresponding cm handle state.
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerAsyncHelper.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerAsyncHelper.java
index cf7921c350..a53c902683 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerAsyncHelper.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerAsyncHelper.java
@@ -1,6 +1,6 @@
 /*
  * ============LICENSE_START=======================================================
- * Copyright (C) 2023 Nordix Foundation
+ * Copyright (C) 2023-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.
@@ -26,6 +26,7 @@ import org.onap.cps.ncmp.api.inventory.models.NcmpServiceCmHandle;
 import org.onap.cps.ncmp.events.lcm.v1.LcmEvent;
 import org.onap.cps.ncmp.events.lcm.v1.LcmEventHeader;
 import org.onap.cps.ncmp.impl.inventory.models.YangModelCmHandle;
+import org.onap.cps.ncmp.impl.inventory.sync.lcm.LcmEventsCmHandleStateHandlerImpl.CmHandleTransitionPair;
 import org.onap.cps.ncmp.impl.utils.YangDataConverter;
 import org.springframework.scheduling.annotation.Async;
 import org.springframework.stereotype.Service;
@@ -38,25 +39,12 @@ public class LcmEventsCmHandleStateHandlerAsyncHelper {
     private final LcmEventsService lcmEventsService;
 
     /**
-     * Publish LCM Event in asynchronous manner.
-     *
-     * @param targetNcmpServiceCmHandle  target NcmpServiceCmHandle
-     * @param currentNcmpServiceCmHandle current NcmpServiceCmHandle
-     */
-    @Async("notificationExecutor")
-    public void publishLcmEventAsynchronously(final NcmpServiceCmHandle targetNcmpServiceCmHandle,
-                                              final NcmpServiceCmHandle currentNcmpServiceCmHandle) {
-        publishLcmEvent(targetNcmpServiceCmHandle, currentNcmpServiceCmHandle);
-    }
-
-    /**
      * Publish LcmEvent in batches and in asynchronous manner.
      *
      * @param cmHandleTransitionPairs Pair of existing and modified cm handle represented as YangModelCmHandle
      */
     @Async("notificationExecutor")
-    public void publishLcmEventBatchAsynchronously(
-            final Collection<LcmEventsCmHandleStateHandlerImpl.CmHandleTransitionPair> cmHandleTransitionPairs) {
+    public void publishLcmEventBatchAsynchronously(final Collection<CmHandleTransitionPair> cmHandleTransitionPairs) {
         cmHandleTransitionPairs.forEach(cmHandleTransitionPair -> publishLcmEvent(
                 toNcmpServiceCmHandle(cmHandleTransitionPair.getTargetYangModelCmHandle()),
                 toNcmpServiceCmHandle(cmHandleTransitionPair.getCurrentYangModelCmHandle())));
diff --git a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerImpl.java b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerImpl.java
index b1b7b955f7..e9bd37219a 100644
--- a/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerImpl.java
+++ b/cps-ncmp-service/src/main/java/org/onap/cps/ncmp/impl/inventory/sync/lcm/LcmEventsCmHandleStateHandlerImpl.java
@@ -38,12 +38,10 @@ import lombok.RequiredArgsConstructor;
 import lombok.Setter;
 import lombok.extern.slf4j.Slf4j;
 import org.onap.cps.ncmp.api.inventory.models.CompositeState;
-import org.onap.cps.ncmp.api.inventory.models.NcmpServiceCmHandle;
 import org.onap.cps.ncmp.impl.inventory.CompositeStateUtils;
 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.utils.YangDataConverter;
 import org.springframework.stereotype.Service;
 
 @Slf4j
@@ -55,25 +53,6 @@ public class LcmEventsCmHandleStateHandlerImpl implements LcmEventsCmHandleState
     private final LcmEventsCmHandleStateHandlerAsyncHelper lcmEventsCmHandleStateHandlerAsyncHelper;
 
     @Override
-    public void updateCmHandleState(final YangModelCmHandle updatedYangModelCmHandle,
-            final CmHandleState targetCmHandleState) {
-
-        final CompositeState compositeState = updatedYangModelCmHandle.getCompositeState();
-
-        if (isCompositeStateSame(compositeState, targetCmHandleState)) {
-            log.debug("CmHandle with id : {} already in state : {}", updatedYangModelCmHandle.getId(),
-                    targetCmHandleState);
-        } else {
-            final YangModelCmHandle currentYangModelCmHandle = YangModelCmHandle.deepCopyOf(updatedYangModelCmHandle);
-            updateToSpecifiedCmHandleState(updatedYangModelCmHandle, targetCmHandleState);
-            persistCmHandle(updatedYangModelCmHandle, currentYangModelCmHandle);
-            lcmEventsCmHandleStateHandlerAsyncHelper.publishLcmEventAsynchronously(
-                    toNcmpServiceCmHandle(updatedYangModelCmHandle),
-                    toNcmpServiceCmHandle(currentYangModelCmHandle));
-        }
-    }
-
-    @Override
     @Timed(value = "cps.ncmp.cmhandle.state.update.batch",
             description = "Time taken to update a batch of cm handle states")
     public void updateCmHandleStateBatch(final Map<YangModelCmHandle, CmHandleState> cmHandleStatePerCmHandle) {
@@ -113,28 +92,13 @@ public class LcmEventsCmHandleStateHandlerImpl implements LcmEventsCmHandleState
         return cmHandleTransitionPairs;
     }
 
-
-    private void persistCmHandle(final YangModelCmHandle targetYangModelCmHandle,
-            final YangModelCmHandle currentYangModelCmHandle) {
-        if (isNew(currentYangModelCmHandle.getCompositeState())) {
-            log.debug("Registering a new cm handle {}", targetYangModelCmHandle.getId());
-            inventoryPersistence.saveCmHandle(targetYangModelCmHandle);
-        } else if (isDeleted(targetYangModelCmHandle.getCompositeState())) {
-            log.info("CmHandle with Id : {} is DELETED", targetYangModelCmHandle.getId());
-        } else {
-            inventoryPersistence.saveCmHandleState(targetYangModelCmHandle.getId(),
-                    targetYangModelCmHandle.getCompositeState());
-        }
-    }
-
     private void persistCmHandleBatch(final Collection<CmHandleTransitionPair> cmHandleTransitionPairs) {
 
         final List<YangModelCmHandle> newCmHandles = new ArrayList<>();
         final Map<String, CompositeState> compositeStatePerCmHandleId = new LinkedHashMap<>();
 
         cmHandleTransitionPairs.forEach(cmHandleTransitionPair -> {
-            if (isNew(cmHandleTransitionPair.getCurrentYangModelCmHandle().getCompositeState()
-            )) {
+            if (isNew(cmHandleTransitionPair.getCurrentYangModelCmHandle().getCompositeState())) {
                 newCmHandles.add(cmHandleTransitionPair.getTargetYangModelCmHandle());
             } else if (!isDeleted(cmHandleTransitionPair.getTargetYangModelCmHandle().getCompositeState())) {
                 compositeStatePerCmHandleId.put(cmHandleTransitionPair.getTargetYangModelCmHandle().getId(),
@@ -145,10 +109,11 @@ public class LcmEventsCmHandleStateHandlerImpl implements LcmEventsCmHandleState
         inventoryPersistence.saveCmHandleBatch(newCmHandles);
         inventoryPersistence.saveCmHandleStateBatch(compositeStatePerCmHandleId);
 
+        logCmHandleStateChanges(cmHandleTransitionPairs);
     }
 
     private void updateToSpecifiedCmHandleState(final YangModelCmHandle yangModelCmHandle,
-            final CmHandleState targetCmHandleState) {
+                                                final CmHandleState targetCmHandleState) {
 
         if (READY == targetCmHandleState) {
             setInitialStates(yangModelCmHandle);
@@ -193,8 +158,11 @@ public class LcmEventsCmHandleStateHandlerImpl implements LcmEventsCmHandleState
         return (compositeState != null && compositeState.getCmHandleState() == targetCmHandleState);
     }
 
-    private NcmpServiceCmHandle toNcmpServiceCmHandle(final YangModelCmHandle yangModelCmHandle) {
-        return YangDataConverter.toNcmpServiceCmHandle(yangModelCmHandle);
+    private static void logCmHandleStateChanges(final Collection<CmHandleTransitionPair> cmHandleTransitionPairs) {
+        cmHandleTransitionPairs.stream()
+                .map(CmHandleTransitionPair::getTargetYangModelCmHandle)
+                .forEach(yangModelCmHandle -> log.info("{} is now in {} state", yangModelCmHandle.getId(),
+                        yangModelCmHandle.getCompositeState().getCmHandleState().name()));
     }
 
     @Getter