Merge "transaction logging through feature part 2"

3 files changed, 125 insertions, 17 deletions

diff --git a/controlloop/common/feature-controlloop-trans/src/main/java/org/onap/policy/drools/apps/controlloop/feature/trans/ControlLoopMetrics.java b/controlloop/common/feature-controlloop-trans/src/main/java/org/onap/policy/drools/apps/controlloop/feature/trans/ControlLoopMetrics.java
index 9306514ad..84d3aae03 100644
--- a/controlloop/common/feature-controlloop-trans/src/main/java/org/onap/policy/drools/apps/controlloop/feature/trans/ControlLoopMetrics.java
+++ b/controlloop/common/feature-controlloop-trans/src/main/java/org/onap/policy/drools/apps/controlloop/feature/trans/ControlLoopMetrics.java
@@ -25,15 +25,18 @@ import com.google.common.cache.CacheLoader;
 import com.google.common.cache.LoadingCache;
 import com.google.common.cache.RemovalListener;
 import com.google.common.cache.RemovalNotification;
+import java.time.Instant;
 import java.time.ZonedDateTime;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Properties;
 import java.util.UUID;
 import java.util.concurrent.TimeUnit;
+import org.onap.policy.controlloop.ControlLoopOperation;
 import org.onap.policy.controlloop.VirtualControlLoopNotification;
 import org.onap.policy.drools.persistence.SystemPersistence;
 import org.onap.policy.drools.system.PolicyController;
+import org.onap.policy.drools.utils.logging.MDCTransaction;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
@@ -76,7 +79,6 @@ public interface ControlLoopMetrics {
      * removes an in-progress transaction
      *
      * @param requestId request ID
-     * @return in progress notification
      */
     void removeTransaction(UUID requestId);
 
@@ -195,8 +197,7 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
                 if (notification.wasEvicted()) {
                     evicted(notification.getValue());
                 } else {
-                    logger.info("REMOVAL: {}->{} from {} because of {}", notification.getValue().getFrom(),
-                        notification.getValue(), notification.getCause().name());
+                    logger.info("REMOVAL: {} because of {}", notification.getValue().getRequestID(), notification.getCause().name());
                 }
             }
         };
@@ -241,8 +242,6 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
 
         notification.setFrom(notification.getFrom() + ":" + controller.getName());
 
-        this.metric(notification);
-
         switch (notification.getNotification()) {
             case REJECTED:
             case FINAL_FAILURE:
@@ -250,10 +249,18 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
             case FINAL_OPENLOOP:
                 endTransaction(notification);
                 break;
-            default:
+            case ACTIVE:
+            case OPERATION:
+            case OPERATION_SUCCESS:
+            case OPERATION_FAILURE:
                 /* any other value is an in progress transaction */
                 inProgressTransaction(notification);
                 break;
+            default:
+                /* unexpected */
+                logger.warn("unexpected notification type {} in notification {}",
+                    notification.getNotification().toString(), notification);
+                break;
         }
     }
 
@@ -276,6 +283,8 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
         if (cache.getIfPresent(notification.getRequestID()) == null) {
             cache.put(notification.getRequestID(), notification);
         }
+
+        this.metric(notification);
     }
 
     /**
@@ -293,12 +302,19 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
         }
 
         this.transaction(notification, startTime);
-
         cache.invalidate(startNotification);
     }
 
     protected void evicted(VirtualControlLoopNotification notification) {
-        transaction(notification, ZonedDateTime.now());
+        // transaction(notification, ZonedDateTime.now());
+        MDCTransaction trans =
+            MDCTransaction.newTransaction(notification.getRequestID().toString(), notification.getFrom()).
+                setServiceName(notification.getClosedLoopControlName()).
+                setTargetEntity(notification.getTarget()).
+                setStartTime(notification.getNotificationTime().toInstant()).
+                setEndTime(Instant.now()).
+                setResponseDescription("EVICTED").
+                setStatusCode(false).metric().resetTransaction();
     }
 
     @Override
@@ -327,17 +343,100 @@ class CacheBasedControlLoopMetricsManager implements ControlLoopMetrics {
     }
 
     protected void metric(VirtualControlLoopNotification notification) {
-        // TODO: next review
-        // set up MDC
-        // logger.info(LoggerUtil.METRIC_LOG_MARKER, "METRIC:{}", notification);
+        MDCTransaction trans =
+            MDCTransaction.newTransaction(notification.getRequestID().toString(), notification.getFrom()).
+                setServiceName(notification.getClosedLoopControlName()).
+                setTargetEntity(notification.getTarget());
+
+        List<ControlLoopOperation> operations = notification.getHistory();
+        switch (notification.getNotification()) {
+            case ACTIVE:
+                trans.setStatusCode(true);
+                trans.metric().resetTransaction();
+                break;
+            case OPERATION:
+                trans.setStatusCode(true);
+                if (!operations.isEmpty()) {
+                    ControlLoopOperation operation = operations.get(operations.size()-1);
+                    trans.setTargetEntity(operation.getTarget());
+                    trans.setTargetServiceName(operation.getActor());
+                }
+                trans.metric().resetTransaction();
+                break;
+            case OPERATION_SUCCESS:
+                trans.setStatusCode(true);
+                operation(trans, operations);
+                trans.transaction().resetTransaction();
+                break;
+            case OPERATION_FAILURE:
+                trans.setStatusCode(false);
+                operation(trans, operations);
+                trans.transaction().resetTransaction();
+                break;
+            default:
+                /* unexpected */
+                logger.warn("unexpected notification type {} in notification {}",
+                    notification.getNotification().toString(), notification);
+                break;
+        }
+    }
+
+    protected void operation(MDCTransaction trans, List<ControlLoopOperation> operations) {
+        if (!operations.isEmpty()) {
+            ControlLoopOperation operation = operations.get(operations.size()-1);
+
+            if (operation.getTarget() != null)
+                trans.setTargetEntity(operation.getTarget());
+
+            if (operation.getActor() != null)
+                trans.setTargetServiceName(operation.getActor());
+
+            if (operation.getMessage() != null)
+                trans.setResponseDescription(operation.getMessage());
+
+            trans.setInvocationId(operation.getSubRequestId());
+
+            if (operation.getOutcome() != null)
+                trans.setResponseCode(operation.getOutcome());
+
+            if (operation.getStart() != null)
+                trans.setStartTime(operation.getStart());
+
+            if (operation.getEnd() != null)
+                trans.setEndTime(operation.getEnd());
+        }
     }
 
     protected void transaction(VirtualControlLoopNotification notification, ZonedDateTime startTime) {
-        // TODO: next review
-        // set up MDC
-        // Duration.between(notification.getNotificationTime(), ZonedDateTime.now()).toMillis())
-        // logger.info(LoggerUtil.TRANSACTION_LOG_MARKER, "TRANSACTION:{}->{} {} ms.", notification.getRequestID(), notification,
-        //  durationMs);
+        MDCTransaction trans =
+            MDCTransaction.newTransaction(notification.getRequestID().toString(), notification.getFrom()).
+                setServiceName(notification.getClosedLoopControlName()).
+                setTargetEntity(notification.getTarget()).
+                setStartTime(startTime.toInstant()).
+                setEndTime(notification.getNotificationTime().toInstant()).
+                setResponseDescription(notification.getMessage());
+
+        switch (notification.getNotification()) {
+            case FINAL_OPENLOOP:
+                trans.setStatusCode(true);
+                break;
+            case FINAL_SUCCESS:
+                trans.setStatusCode(true);
+                break;
+            case FINAL_FAILURE:
+                trans.setStatusCode(false);
+                break;
+            case REJECTED:
+                trans.setStatusCode(false);
+                break;
+            default:
+                /* unexpected */
+                logger.warn("unexpected notification type {} in notification {}",
+                    notification.getNotification().toString(), notification);
+                break;
+        }
+
+        trans.transaction().resetTransaction();
     }
 
     @Override
diff --git a/controlloop/packages/apps/pom.xml b/controlloop/packages/apps/pom.xml
index 1e5acf6a8..db843b55b 100644
--- a/controlloop/packages/apps/pom.xml
+++ b/controlloop/packages/apps/pom.xml
@@ -76,6 +76,12 @@
       <version>${project.version}</version>
       <type>zip</type>
     </dependency>
+    <dependency>
+      <groupId>org.onap.policy.drools-applications.controlloop.common</groupId>
+      <artifactId>feature-controlloop-trans</artifactId>
+      <version>${project.version}</version>
+      <type>zip</type>
+    </dependency>
   </dependencies>
 
 </project>
diff --git a/controlloop/packages/apps/src/files/apps-installer b/controlloop/packages/apps/src/files/apps-installer
index d483707b9..cff4376f7 100644
--- a/controlloop/packages/apps/src/files/apps-installer
+++ b/controlloop/packages/apps/src/files/apps-installer
@@ -33,6 +33,9 @@ echo
 
 source ${POLICY_HOME}/etc/build.info
 
+features install controlloop-trans
+features enable controlloop-trans
+
 # caching in local maven repo all dependencies to make it
 # easier for drools kie-ci - aether to fetch them
 
@@ -47,7 +50,7 @@ mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.on
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.model-impl:trafficgenerator:${version}:jar -Dtransitive=false
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications:controlloop.common:eventmanager:${version}:jar -Dtransitive=false
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common:guard:${version}:jar -Dtransitive=false
-mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.actors:actorserviceprovider:${version}:jar -Dtransitive=false
+mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.actors:actorServiceProvider:${version}:jar -Dtransitive=false
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.actors:actor.appc:${version}:jar -Dtransitive=false
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.actors:actor.appclcm:${version}:jar -Dtransitive=false
 mvn org.apache.maven.plugins:maven-dependency-plugin:3.0.2:get -Dartifact=org.onap.policy.drools-applications.controlloop.common.actors:actor.so:${version}:jar -Dtransitive=false