azkaban-aplcache

flow trigger service logging improvement (#1787) 1. use

6/4/2018 7:55:50 PM

Details

diff --git a/azkaban-web-server/src/main/java/azkaban/flowtrigger/DependencyInstanceProcessor.java b/azkaban-web-server/src/main/java/azkaban/flowtrigger/DependencyInstanceProcessor.java
index de97228..b3ab160 100644
--- a/azkaban-web-server/src/main/java/azkaban/flowtrigger/DependencyInstanceProcessor.java
+++ b/azkaban-web-server/src/main/java/azkaban/flowtrigger/DependencyInstanceProcessor.java
@@ -19,13 +19,10 @@ package azkaban.flowtrigger;
 import azkaban.flowtrigger.database.FlowTriggerInstanceLoader;
 import javax.inject.Inject;
 import javax.inject.Singleton;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 
 @Singleton
 public class DependencyInstanceProcessor {
 
-  private static final Logger logger = LoggerFactory.getLogger(DependencyInstanceProcessor.class);
   private final FlowTriggerInstanceLoader flowTriggerInstanceLoader;
 
   @Inject
@@ -37,7 +34,6 @@ public class DependencyInstanceProcessor {
    * Process status update of dependency instance
    */
   public void processStatusUpdate(final DependencyInstance depInst) {
-    logger.debug("process status update for " + depInst);
     //this is blocking call, might offload it to another thread if necessary.
     this.flowTriggerInstanceLoader.updateDependencyExecutionStatus(depInst);
   }
diff --git a/azkaban-web-server/src/main/java/azkaban/flowtrigger/FlowTriggerService.java b/azkaban-web-server/src/main/java/azkaban/flowtrigger/FlowTriggerService.java
index a1cc031..e900761 100644
--- a/azkaban-web-server/src/main/java/azkaban/flowtrigger/FlowTriggerService.java
+++ b/azkaban-web-server/src/main/java/azkaban/flowtrigger/FlowTriggerService.java
@@ -146,8 +146,8 @@ public class FlowTriggerService {
       try {
         context = createDepContext(dep, startTime, triggerInstId);
       } catch (final Exception ex) {
-        logger.error(String.format("unable to create dependency context for trigger instance[id ="
-            + " %s]", triggerInstId), ex);
+        logger.error("unable to create dependency context for trigger instance[id = {}]",
+            triggerInstId, ex);
       }
       // if dependency instance context fails to be created, then its status is cancelled and
       // cause is failure
@@ -173,8 +173,8 @@ public class FlowTriggerService {
   private void scheduleKill(final TriggerInstance triggerInst, final Duration duration, final
   CancellationCause cause) {
     logger
-        .debug(String.format("Cancel trigger instance %s in %s secs", triggerInst.getId(), duration
-            .getSeconds()));
+        .debug("cancel trigger instance {} in {} secs", triggerInst.getId(), duration
+            .getSeconds());
     this.timeoutService.schedule(() -> {
       cancelTriggerInstance(triggerInst, cause);
     }, duration.toMillis(), TimeUnit.MILLISECONDS);
@@ -221,8 +221,8 @@ public class FlowTriggerService {
         } catch (final Exception ex) {
           logger
               .error(
-                  String.format("unable to create dependency context for trigger instance[id ="
-                      + " %s]", triggerInstance.getId()), ex);
+                  "unable to create dependency context for trigger instance[id ="
+                      + " {}]", triggerInstance.getId(), ex);
         }
         depInst.setDependencyInstanceContext(context);
         if (context == null) {
@@ -246,8 +246,7 @@ public class FlowTriggerService {
   }
 
   private void recover(final TriggerInstance triggerInstance) {
-    logger.info(String.format("recovering pending trigger instance %s", triggerInstance.getId
-        ()));
+    logger.info("recovering pending trigger instance {}", triggerInstance.getId());
     if (isDoneButFlowNotExecuted(triggerInstance)) {
       // if trigger instance succeeds but the associated flow hasn't been started yet, then start
       // the flow
@@ -267,8 +266,8 @@ public class FlowTriggerService {
       if (triggerInstance.getFlowTrigger() != null) {
         recoverTriggerInstance(triggerInstance);
       } else {
-        logger.error(String.format("cannot recover the trigger instance %s, flow trigger is null,"
-            + " cancelling it ", triggerInstance.getId()));
+        logger.error("cannot recover the trigger instance {}, flow trigger is null,"
+            + " cancelling it ", triggerInstance.getId());
 
         //finalize unrecoverable trigger instances
         // the following situation would cause trigger instances unrecoverable:
@@ -378,9 +377,8 @@ public class FlowTriggerService {
     final TriggerInstance triggerInst = createTriggerInstance(flowTrigger, flowId, flowVersion,
         submitUser, project);
     this.flowTriggerExecutorService.submit(() -> {
-      logger.info(
-          String.format("Starting the flow trigger %s[trigger instance id: %s] by %s", flowTrigger,
-              triggerInst.getId(), submitUser));
+      logger.info("Starting the flow trigger [trigger instance id: {}] by {}",
+          triggerInst.getId(), submitUser);
       start(triggerInst);
     });
   }
@@ -389,14 +387,15 @@ public class FlowTriggerService {
     this.triggerProcessor.processNewInstance(triggerInst);
     if (triggerInst.getStatus() == Status.CANCELLED) {
       // all dependency instances failed
-      logger.info(String.format("Trigger instance[id: %s] is cancelled since all dependency "
-          + "instances fail to be created", triggerInst.getId()));
+      logger.info(
+          "Trigger instance[id: {}] is cancelled since all dependency instances fail to be created",
+          triggerInst.getId());
       this.triggerProcessor.processTermination(triggerInst);
     } else if (triggerInst.getStatus() == Status.CANCELLING) {
       // some of the dependency instances failed
       logger.info(
-          String.format("Trigger instance[id: %s] is being cancelled since some dependency "
-              + "instances fail to be created", triggerInst.getId()));
+          "Trigger instance[id: {}] is being cancelled since some dependency instances fail to be created",
+          triggerInst.getId());
       addToRunningListAndCancel(triggerInst);
     } else if (triggerInst.getStatus() == Status.SUCCEEDED) {
       this.triggerProcessor.processSucceed(triggerInst);
@@ -438,12 +437,13 @@ public class FlowTriggerService {
    */
   public void cancelTriggerInstance(final TriggerInstance triggerInst,
       final CancellationCause cause) {
-    this.flowTriggerExecutorService.submit(() -> cancel(triggerInst, cause));
+    if (triggerInst.getStatus() == Status.RUNNING) {
+      this.flowTriggerExecutorService.submit(() -> cancel(triggerInst, cause));
+    }
   }
 
   private void cancel(final TriggerInstance triggerInst, final CancellationCause cause) {
-    logger.info(
-        String.format("cancelling trigger instance with id %s", triggerInst.getId()));
+    logger.info("cancelling trigger instance with id {}", triggerInst.getId());
     if (triggerInst != null) {
       for (final DependencyInstance depInst : triggerInst.getDepInstances()) {
         // cancel running dependencies only, no need to cancel a killed/successful dependency
@@ -454,10 +454,8 @@ public class FlowTriggerService {
         }
       }
     } else {
-      logger.debug(String
-          .format(
-              "unable to cancel a trigger instance in non-running state with id %s",
-              triggerInst.getId()));
+      logger.debug("unable to cancel a trigger instance in non-running state with id {}",
+          triggerInst.getId());
     }
   }
 
@@ -480,28 +478,23 @@ public class FlowTriggerService {
     final DependencyInstance depInst = findDependencyInstanceByContext(context);
     if (depInst != null) {
       if (Status.isDone(depInst.getStatus())) {
-        logger.warn(String.format("OnSuccess of dependency instance[id: %s, name: %s] is ignored",
-            depInst.getTriggerInstance().getId(), depInst.getDepName()));
+        logger.warn("OnSuccess of dependency instance[id: {}, name: {}] is ignored",
+            depInst.getTriggerInstance().getId(), depInst.getDepName());
         return;
       }
 
-      logger.info(
-          String.format("setting dependency instance[id: %s, name: %s] status to succeeded",
-              depInst.getTriggerInstance().getId(), depInst.getDepName()));
       // if the status transits from cancelling to succeeded, then cancellation cause was set,
       // we need to unset cancellation cause.
       this.processStatusAndCancelCauseUpdate(depInst, Status.SUCCEEDED, CancellationCause.NONE);
       // if associated trigger instance becomes success, then remove it from running list
       if (depInst.getTriggerInstance().getStatus() == Status.SUCCEEDED) {
-        logger.info(String.format("trigger instance[id: %s] succeeded",
-            depInst.getTriggerInstance().getId()));
+        logger.info("trigger instance[id: {}] succeeded", depInst.getTriggerInstance().getId());
         this.triggerProcessor.processSucceed(depInst.getTriggerInstance());
         this.runningTriggers.remove(depInst.getTriggerInstance());
       }
     } else {
-      logger.debug(String.format("unable to find trigger instance with context %s when marking "
-              + "it success",
-          context));
+      logger.debug("unable to find trigger instance with context {} when marking it success",
+          context);
     }
   }
 
@@ -525,29 +518,26 @@ public class FlowTriggerService {
   private void markCancelled(final DependencyInstanceContext context) {
     final DependencyInstance depInst = findDependencyInstanceByContext(context);
     if (depInst != null) {
-      logger.info(String.format("set dependency instance[id: %s, name: %s] status to "
-          + "cancelled", depInst.getTriggerInstance().getId(), depInst.getDepName()));
       if (cancelledByDependencyPlugin(depInst)) {
         processStatusAndCancelCauseUpdate(depInst, Status.CANCELLED, CancellationCause.FAILURE);
         cancelTriggerInstance(depInst.getTriggerInstance());
       } else if (cancelledByAzkaban(depInst)) {
         processStatusUpdate(depInst, Status.CANCELLED);
       } else {
-        logger.warn(String.format("OnCancel of dependency instance[id: %s, name: %s] is ignored",
-            depInst.getTriggerInstance().getId(), depInst.getDepName()));
+        logger.warn("OnCancel of dependency instance[id: {}, name: {}] is ignored",
+            depInst.getTriggerInstance().getId(), depInst.getDepName());
         return;
       }
 
       if (depInst.getTriggerInstance().getStatus() == Status.CANCELLED) {
-        logger.info(
-            String.format("trigger instance with execId %s is cancelled",
-                depInst.getTriggerInstance().getId()));
+        logger.info("trigger instance with execId {} is cancelled",
+            depInst.getTriggerInstance().getId());
         this.triggerProcessor.processTermination(depInst.getTriggerInstance());
         this.runningTriggers.remove(depInst.getTriggerInstance());
       }
     } else {
-      logger.warn(String.format("unable to find trigger instance with context %s when marking "
-          + "it cancelled", context));
+      logger.warn("unable to find trigger instance with context {} when marking "
+          + "it cancelled", context);
     }
   }
 
diff --git a/azkaban-web-server/src/main/java/azkaban/flowtrigger/TriggerInstanceProcessor.java b/azkaban-web-server/src/main/java/azkaban/flowtrigger/TriggerInstanceProcessor.java
index 69eebf1..4673e98 100644
--- a/azkaban-web-server/src/main/java/azkaban/flowtrigger/TriggerInstanceProcessor.java
+++ b/azkaban-web-server/src/main/java/azkaban/flowtrigger/TriggerInstanceProcessor.java
@@ -73,9 +73,9 @@ public class TriggerInstanceProcessor {
       this.executorManager.submitExecutableFlow(executableFlow, triggerInst.getSubmitUser());
       triggerInst.setFlowExecId(executableFlow.getExecutionId());
     } catch (final Exception ex) {
-      logger.error(String.format(
-          "exception when executing the associated flow and updating flow exec id for trigger instance[id: %s]",
-          triggerInst.getId()), ex);
+      logger.error("exception when executing the associated flow and updating flow exec id for "
+              + "trigger instance[id: {}]",
+          triggerInst.getId(), ex);
       // if flow fails to be executed(e.g. running execution exceeds the allowed concurrent run
       // limit), set associated flow exec id to Constants.FAILED_EXEC_ID. Upon web server
       // restart, recovery process will skip those flows.
@@ -144,7 +144,6 @@ public class TriggerInstanceProcessor {
    * Process the case where status of trigger instance becomes success
    */
   public void processSucceed(final TriggerInstance triggerInst) {
-    logger.debug("process succeed for " + triggerInst);
     //todo chengren311: publishing Trigger events to Azkaban Project Events page
     executeFlowAndUpdateExecID(triggerInst);
   }
@@ -153,7 +152,6 @@ public class TriggerInstanceProcessor {
    * Process the case where status of trigger instance becomes cancelled
    */
   public void processTermination(final TriggerInstance triggerInst) {
-    logger.debug("process termination for " + triggerInst);
     //sendFailureEmailIfConfigured takes 1/3 secs
     this.executorService.submit(() -> sendFailureEmailIfConfigured(triggerInst));
   }
@@ -162,7 +160,6 @@ public class TriggerInstanceProcessor {
    * Process the case where a new trigger instance is created
    */
   public void processNewInstance(final TriggerInstance triggerInst) {
-    logger.debug("process new instance for " + triggerInst);
     this.flowTriggerInstanceLoader.uploadTriggerInstance(triggerInst);
   }