Improve performance for large pipeline graphs (#503)

Author: johannesacco

src/main/java/io/jenkins/plugins/pipelinegraphview/treescanner/NodeRelationship.java

@@ -37,13 +37,6 @@ public NodeRelationship(@NonNull FlowNode start, @NonNull FlowNode end, @CheckFo
         this.end = end;
     }
 
-    // Print debug message if 'isDebugEnabled' is true.
-    protected void dump(String message, Object... args) {
-        if (isDebugEnabled) {
-            logger.debug(String.format(message, args));
-        }
-    }
-
     /*
      * Returns the recorded node that was run before this node
      * Returns null if unset (e.g.)
@@ -92,9 +85,13 @@ public FlowNode getEnd() {
      */
     public @NonNull TimingInfo getTimingInfo(@NonNull WorkflowRun run) {
         long pause = PauseAction.getPauseDuration(this.start);
-        dump(
-                "Calculating Chunk Timing info start: %s, end: %s after: %s",
-                this.start.getId(), this.end.getId(), (this.after != null) ? this.after.getId() : "null");
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Calculating Chunk Timing info start: {}, end: {} after: {}",
+                    this.start.getId(),
+                    this.end.getId(),
+                    (this.after != null) ? this.after.getId() : "null");
+        }
         TimingInfo timing = StatusAndTiming.computeChunkTiming(run, pause, this.start, this.end, this.after);
         if (timing != null) {
             return timing;
@@ -112,9 +109,13 @@ public FlowNode getEnd() {
         } else if (PipelineNodeUtil.isPaused(this.end)) {
             return new NodeRunStatus(BlueRun.BlueRunResult.UNKNOWN, BlueRun.BlueRunState.PAUSED);
         }
-        dump(
-                "Calculating Chunk Status start: %s, end: %s after: %s",
-                this.start.getId(), this.end.getId(), (this.after != null) ? this.after.getId() : "null");
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Calculating Chunk Status start: {}, end: {} after: {}",
+                    this.start.getId(),
+                    this.end.getId(),
+                    (this.after != null) ? this.after.getId() : "null");
+        }
 
         // If start and end are equal this is a StepNode
         if (this.start.getId().equals(this.end.getId())) {

src/main/java/io/jenkins/plugins/pipelinegraphview/treescanner/NodeRelationshipFinder.java

@@ -42,13 +42,6 @@ public class NodeRelationshipFinder {
 
     private LinkedHashMap<String, NodeRelationship> relationships = new LinkedHashMap<>();
 
-    // Print debug message if 'isDebugEnabled' is true.
-    private void dump(String message, Object... args) {
-        if (isDebugEnabled) {
-            logger.debug(String.format(message, args));
-        }
-    }
-
     public NodeRelationshipFinder() {}
 
     /**
@@ -57,14 +50,18 @@ public NodeRelationshipFinder() {}
     @NonNull
     public LinkedHashMap<String, NodeRelationship> getNodeRelationships(
             @NonNull LinkedHashMap<String, FlowNode> nodeMap) {
-        dump("Original Ids: %s", String.join(", ", nodeMap.keySet()));
+        if (isDebugEnabled) {
+            logger.debug("Original Ids: {}", String.join(", ", nodeMap.keySet()));
+        }
         // This is important, determining the the relationships depends on the order of
         // iteration.
         // If there was a method to tell if a node was a parallel block this might be
         // less of an issue.
         List<String> sortedIds = new ArrayList<>(nodeMap.keySet());
         Collections.sort(sortedIds, new FlowNodeWrapper.NodeIdComparator().reversed());
-        dump("Sorted Ids: %s", String.join(", ", sortedIds));
+        if (isDebugEnabled) {
+            logger.debug("Sorted Ids: {}", String.join(", ", sortedIds));
+        }
         for (String id : sortedIds) {
             getRelationshipForNode(nodeMap.get(id));
             // Add this node to the parents's stack as the last of it's child nodes that
@@ -90,15 +87,17 @@ private void handleBlockStart(@NonNull FlowNode node) {
         if (FlowNodeWrapper.isStart(node)) {
             addBlockRelationship(node);
         } else {
-            dump("Why are we here?? %s - %s", node.getId(), node.getClass());
+            logger.debug("Why are we here?? {} - {}", node.getId(), node.getClass());
         }
     }
 
     private void addSeenNodes(FlowNode node) {
         if (!seenChildNodes.keySet().contains(node.getEnclosingId())) {
             seenChildNodes.put(node.getEnclosingId(), new ArrayDeque<FlowNode>());
         }
-        dump("Adding %s to seenChildNodes %s", node.getId(), node.getEnclosingId());
+        if (isDebugEnabled) {
+            logger.debug("Adding {} to seenChildNodes {}", node.getId(), node.getEnclosingId());
+        }
         seenChildNodes.get(node.getEnclosingId()).push(node);
     }
 
@@ -113,9 +112,13 @@ private FlowNode getAfterNode(FlowNode node) {
             // If there are no later siblings, get the parents later sibling.
             ArrayDeque<FlowNode> parentsLaterSiblings = getProcessedChildren(getFirstEnclosingNode(parentStartNode));
             after = parentsLaterSiblings.isEmpty() ? null : parentsLaterSiblings.peek();
-            dump(parentsLaterSiblings.toString());
+            if (isDebugEnabled) {
+                logger.debug(parentsLaterSiblings.toString());
+            }
         } else {
-            dump(laterSiblings.toString());
+            if (isDebugEnabled) {
+                logger.debug(laterSiblings.toString());
+            }
             after = laterSiblings.peek();
         }
         return after;
@@ -136,15 +139,19 @@ private ArrayDeque<FlowNode> getProcessedChildren(@CheckForNull FlowNode node) {
     }
 
     private void addStepRelationship(@NonNull StepAtomNode step) {
-        dump("Generating relationship for step %s", step.getId());
+        if (isDebugEnabled) {
+            logger.debug("Generating relationship for step {}", step.getId());
+        }
         // FlowNode after = subsequentNode;
         FlowNode after = getAfterNode(step);
-        dump(
-                "Adding step for %s(%s),%s(%s)",
-                step.getId(),
-                step.getClass().getName(),
-                after == null ? "null" : after.getId(),
-                after == null ? "null" : after.getClass().getName());
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Adding step for {}({}),{}({})",
+                    step.getId(),
+                    step.getClass().getName(),
+                    after == null ? "null" : after.getId(),
+                    after == null ? "null" : after.getClass().getName());
+        }
         NodeRelationship nodeRelationship = new NodeRelationship(step, step, after);
         relationships.put(step.getId(), nodeRelationship);
     }
@@ -166,7 +173,9 @@ private void addBlockRelationship(@NonNull FlowNode node) {
         if (PipelineNodeUtil.isParallelBranch(node)) {
             addParallelBranchRelationship(node, endNode);
         } else {
-            dump("Adding relationship for %s", node.getId());
+            if (isDebugEnabled) {
+                logger.debug("Adding relationship for {}", node.getId());
+            }
             if (!pendingBranchRelationships.isEmpty()) {
                 blockRelationship = addParallelRelationship(node, endNode);
             } else {
@@ -186,12 +195,14 @@ private void addParallelBranchRelationship(@NonNull FlowNode node, @NonNull Flow
         // Store a parallel branch relationship - these will be used to build up the
         // parent parallel block relationship.
         // Once generated, that relationship will be superseded this one.
-        dump(
-                "Adding parallel branch relationship for %s(%s)->%s(%s)",
-                node.getId(),
-                node.getClass().getName(),
-                endNode.getId(),
-                endNode.getClass().getName());
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Adding parallel branch relationship for {}({})->{}({})",
+                    node.getId(),
+                    node.getClass().getName(),
+                    endNode.getId(),
+                    endNode.getClass().getName());
+        }
         // After doesn't matter as this relationship object is temporary (only start and
         // end node are used).
         NodeRelationship blockRelationship = new NodeRelationship(node, endNode, after);
@@ -200,9 +211,12 @@ private void addParallelBranchRelationship(@NonNull FlowNode node, @NonNull Flow
 
     private NodeRelationship addParallelRelationship(@NonNull FlowNode node, @NonNull FlowNode endNode) {
         FlowNode after = getAfterNode(node);
-        dump(
-                "Generating relationship for parallel Block %s (with after %s)",
-                node.getId(), (after != null) ? after.getId() : "null");
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Generating relationship for parallel Block {} (with after {})",
+                    node.getId(),
+                    (after != null) ? after.getId() : "null");
+        }
         // handle parallel block case.
         NodeRelationship parallelRelationship =
                 new ParallelBlockRelationship(node, endNode, after, pendingBranchRelationships);
@@ -221,14 +235,16 @@ private NodeRelationship addParallelRelationship(@NonNull FlowNode node, @NonNul
 
     private NodeRelationship addStageRelationship(@NonNull FlowNode node, @NonNull FlowNode endNode) {
         FlowNode after = getAfterNode(node);
-        dump(
-                "Generating relationship for Block %s{%s}->%s{%s} (with after %s{%s})",
-                node.getId(),
-                node.getClass(),
-                endNode.getId(),
-                endNode.getClass(),
-                (after != null) ? after.getId() : "null",
-                (after != null) ? after.getClass() : "null");
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Generating relationship for Block {}{{}}->{}{{}} (with after {}{{}})",
+                    node.getId(),
+                    node.getClass(),
+                    endNode.getId(),
+                    endNode.getClass(),
+                    (after != null) ? after.getId() : "null",
+                    (after != null) ? after.getClass() : "null");
+        }
         return new NodeRelationship(node, endNode, after);
     }
 }

src/main/java/io/jenkins/plugins/pipelinegraphview/treescanner/ParallelBlockRelationship.java

@@ -45,14 +45,6 @@ public ParallelBlockRelationship(
         this.branchEnds = branchEnds;
     }
 
-    // Print debug message if 'isDebugEnabled' is true.
-    @Override
-    protected void dump(String message, Object... args) {
-        if (isDebugEnabled) {
-            logger.debug(String.format(message, args));
-        }
-    }
-
     public ParallelBlockRelationship(
             @NonNull FlowNode start,
             @NonNull FlowNode end,
@@ -125,13 +117,18 @@ private void calculateTimings(WorkflowRun run) {
         for (int i = 0; i < this.branchStarts.size(); i++) {
             FlowNode branchStart = this.branchStarts.get(i);
             FlowNode branchEnd = this.branchEnds.get(i);
-            dump(
-                    "Calculating parallel branch timings %s, %s",
-                    branchStart.getId(), (branchEnd != null) ? branchEnd.getId() : "null");
+            if (isDebugEnabled) {
+                logger.debug(
+                        "Calculating parallel branch timings {}, {}",
+                        branchStart.getId(),
+                        (branchEnd != null) ? branchEnd.getId() : "null");
+            }
         }
         this.branchTimings = StatusAndTiming.computeParallelBranchTimings(
                 run, this.start, this.branchStarts, this.branchEnds, parallelEndNode, pauseDurations);
-        dump("Calculating parallel timings %s, %s (with above branches)", start.getId(), end.getId());
+        if (isDebugEnabled) {
+            logger.debug("Calculating parallel timings {}, {} (with above branches)", start.getId(), end.getId());
+        }
         this.overallTiming =
                 StatusAndTiming.computeOverallParallelTiming(run, this.branchTimings, this.start, parallelEndNode);
     }
@@ -144,7 +141,9 @@ private void calculateTimings(WorkflowRun run) {
         if (this.overallStatus == null) {
             calculateStatuses(run);
         }
-        dump("Overall status for '%s': '%s'", this.start, this.overallStatus);
+        if (isDebugEnabled) {
+            logger.debug("Overall status for '{}': '{}'", this.start, this.overallStatus);
+        }
         return new NodeRunStatus(this.overallStatus);
     }
 
@@ -155,11 +154,13 @@ private void calculateTimings(WorkflowRun run) {
         if (this.branchStatuses == null) {
             calculateStatuses(run);
         }
-        dump(
-                "Branch status for %s (%s): '%s'",
-                branchStartNode.getId(),
-                getBranchName(branchStartNode),
-                this.branchStatuses.get(getBranchName(branchStartNode)));
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Branch status for {} ({}): '{}'",
+                    branchStartNode.getId(),
+                    getBranchName(branchStartNode),
+                    this.branchStatuses.get(getBranchName(branchStartNode)));
+        }
         boolean skippedStage = PipelineNodeUtil.isSkippedStage(branchStartNode);
         return new NodeRunStatus(this.branchStatuses.get(getBranchName(branchStartNode)), skippedStage);
     }
@@ -176,14 +177,19 @@ private void calculateStatuses(WorkflowRun run) {
         for (int i = 0; i < this.branchStarts.size(); i++) {
             BlockStartNode branchStart = this.branchStarts.get(i);
             FlowNode branchEnd = this.branchEnds.get(i);
-            dump(
-                    "Calculating parallel branch status %s, %s: %s",
-                    branchStart.getId(),
-                    (branchEnd != null) ? branchEnd.getId() : "null",
-                    getBranchStatus(run, branchStart));
+            if (isDebugEnabled) {
+                logger.debug(
+                        "Calculating parallel branch status {}, {}: {}",
+                        branchStart.getId(),
+                        (branchEnd != null) ? branchEnd.getId() : "null",
+                        getBranchStatus(run, branchStart));
+            }
         }
 
-        dump("Calculating parallel status %s, %s (with above branches)", this.start.getId(), this.end.getId());
+        if (isDebugEnabled) {
+            logger.debug(
+                    "Calculating parallel status {}, {} (with above branches)", this.start.getId(), this.end.getId());
+        }
         this.overallStatus = StatusAndTiming.condenseStatus(this.branchStatuses.values());
     }
 }