From 78267284c8630decfdaa1fcb011e3268572f361a Mon Sep 17 00:00:00 2001 From: =?utf8?q?S=C3=A9bastien=20Lesaint?= Date: Thu, 24 Sep 2015 18:32:43 +0200 Subject: [PATCH] SONAR-6799 add log of Component visitor cumulative execution duration --- .../component/PathAwareVisitorWrapper.java | 5 ++ .../component/TypeAwareVisitorWrapper.java | 5 ++ .../computation/component/VisitorWrapper.java | 2 + .../component/VisitorsCrawler.java | 55 +++++++++++++++++-- .../computation/step/ExecuteVisitorsStep.java | 24 ++++++-- 5 files changed, 83 insertions(+), 8 deletions(-) diff --git a/server/sonar-server/src/main/java/org/sonar/server/computation/component/PathAwareVisitorWrapper.java b/server/sonar-server/src/main/java/org/sonar/server/computation/component/PathAwareVisitorWrapper.java index 902102e6542..8f804ba5abe 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/computation/component/PathAwareVisitorWrapper.java +++ b/server/sonar-server/src/main/java/org/sonar/server/computation/component/PathAwareVisitorWrapper.java @@ -32,6 +32,11 @@ public class PathAwareVisitorWrapper implements VisitorWrapper { this.delegate = delegate; } + @Override + public ComponentVisitor getWrappedVisitor() { + return this.delegate; + } + @Override public void beforeComponent(Component component){ stack.add(new PathElementImpl<>(component, createForComponent(component))); diff --git a/server/sonar-server/src/main/java/org/sonar/server/computation/component/TypeAwareVisitorWrapper.java b/server/sonar-server/src/main/java/org/sonar/server/computation/component/TypeAwareVisitorWrapper.java index fc04c6e1fa4..a5da916296c 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/computation/component/TypeAwareVisitorWrapper.java +++ b/server/sonar-server/src/main/java/org/sonar/server/computation/component/TypeAwareVisitorWrapper.java @@ -28,6 +28,11 @@ public class TypeAwareVisitorWrapper implements VisitorWrapper { this.delegate = delegate; } + @Override + public ComponentVisitor getWrappedVisitor() { + return this.delegate; + } + @Override public void beforeComponent(Component component){ // Nothing to do diff --git a/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorWrapper.java b/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorWrapper.java index 21a782f0ed6..2a0d7ec656f 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorWrapper.java +++ b/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorWrapper.java @@ -22,6 +22,8 @@ package org.sonar.server.computation.component; public interface VisitorWrapper extends TypeAwareVisitor { + ComponentVisitor getWrappedVisitor(); + void beforeComponent(Component component); void afterComponent(Component component); diff --git a/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorsCrawler.java b/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorsCrawler.java index ea5e20ee9a2..0b030291281 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorsCrawler.java +++ b/server/sonar-server/src/main/java/org/sonar/server/computation/component/VisitorsCrawler.java @@ -23,11 +23,13 @@ package org.sonar.server.computation.component; import com.google.common.base.Function; import com.google.common.base.Predicate; import com.google.common.collect.ImmutableMap; +import com.google.common.collect.Maps; import java.util.List; import java.util.Map; import javax.annotation.Nonnull; -import org.sonar.api.utils.log.Logger; +import javax.annotation.Nullable; import org.sonar.api.utils.log.Loggers; +import org.sonar.core.util.logs.Profiler; import static com.google.common.collect.FluentIterable.from; import static com.google.common.collect.Iterables.concat; @@ -38,8 +40,7 @@ import static java.util.Objects.requireNonNull; */ public class VisitorsCrawler implements ComponentCrawler { - private static final Logger LOGGER = Loggers.get(VisitorsCrawler.class); - + private final Map visitorCumulativeDurations; private final List preOrderVisitorWrappers; private final List postOrderVisitorWrappers; @@ -47,6 +48,13 @@ public class VisitorsCrawler implements ComponentCrawler { List visitorWrappers = from(visitors).transform(ToVisitorWrapper.INSTANCE).toList(); this.preOrderVisitorWrappers = from(visitorWrappers).filter(MathPreOrderVisitor.INSTANCE).toList(); this.postOrderVisitorWrappers = from(visitorWrappers).filter(MatchPostOrderVisitor.INSTANCE).toList(); + this.visitorCumulativeDurations = from(visitors).toMap(VisitorWrapperToInitialDuration.INSTANCE); + } + + public Map getCumulativeDurations() { + return ImmutableMap.copyOf( + Maps.transformValues(this.visitorCumulativeDurations, VisitorDurationToDuration.INSTANCE) + ); } @Override @@ -84,7 +92,8 @@ public class VisitorsCrawler implements ComponentCrawler { } private void visitNode(Component component, VisitorWrapper visitor) { - LOGGER.trace("Visitor '{}' is currently visiting component {}", visitor, component); + Profiler profiler = Profiler.create(Loggers.get(visitor.getWrappedVisitor().getClass())) + .startTrace("Visiting component {}", component.getKey()); visitor.visitAny(component); switch (component.getType()) { case PROJECT: @@ -111,6 +120,12 @@ public class VisitorsCrawler implements ComponentCrawler { default: throw new IllegalStateException(String.format("Unknown type %s", component.getType().name())); } + long duration = profiler.stopTrace(); + incrementDuration(visitor, duration); + } + + private void incrementDuration(VisitorWrapper visitorWrapper, long duration) { + visitorCumulativeDurations.get(visitorWrapper.getWrappedVisitor()).increment(duration); } private enum ToVisitorWrapper implements Function { @@ -173,4 +188,36 @@ public class VisitorsCrawler implements ComponentCrawler { return visitorWrapper.getOrder() == ComponentVisitor.Order.POST_ORDER; } } + + private static final class VisitorDuration { + private long duration = 0; + + public void increment(long duration) { + this.duration += duration; + } + + public long getDuration() { + return duration; + } + } + + private enum VisitorWrapperToInitialDuration implements Function { + INSTANCE; + + @Override + @Nonnull + public VisitorDuration apply(@Nonnull ComponentVisitor visitorWrapper) { + return new VisitorDuration(); + } + } + + private enum VisitorDurationToDuration implements Function { + INSTANCE; + + @Nullable + @Override + public Long apply(VisitorDuration input) { + return input.getDuration(); + } + } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/computation/step/ExecuteVisitorsStep.java b/server/sonar-server/src/main/java/org/sonar/server/computation/step/ExecuteVisitorsStep.java index cf29c473e3c..480a8bdc591 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/computation/step/ExecuteVisitorsStep.java +++ b/server/sonar-server/src/main/java/org/sonar/server/computation/step/ExecuteVisitorsStep.java @@ -21,11 +21,17 @@ package org.sonar.server.computation.step; import java.util.List; +import java.util.Map; +import org.sonar.api.utils.log.Logger; +import org.sonar.api.utils.log.Loggers; import org.sonar.server.computation.component.ComponentVisitor; import org.sonar.server.computation.component.TreeRootHolder; import org.sonar.server.computation.component.VisitorsCrawler; public class ExecuteVisitorsStep implements ComputationStep { + + private static final Logger LOGGER = Loggers.get(ExecuteVisitorsStep.class); + private final TreeRootHolder treeRootHolder; private final List visitors; @@ -35,12 +41,22 @@ public class ExecuteVisitorsStep implements ComputationStep { } @Override - public void execute() { - new VisitorsCrawler(visitors).visit(treeRootHolder.getRoot()); + public String getDescription() { + return "Execute Component Visitors"; } @Override - public String getDescription() { - return "Execute visitors"; + public void execute() { + VisitorsCrawler visitorsCrawler = new VisitorsCrawler(visitors); + visitorsCrawler.visit(treeRootHolder.getRoot()); + logVisitorExecutionDurations(visitors, visitorsCrawler); + } + + private static void logVisitorExecutionDurations(List visitors, VisitorsCrawler visitorsCrawler) { + LOGGER.info(" Execution time for each Component visitor:"); + Map cumulativeDurations = visitorsCrawler.getCumulativeDurations(); + for (ComponentVisitor visitor : visitors) { + LOGGER.info(" - {} | time={}ms", visitor.getClass().getSimpleName(), cumulativeDurations.get(visitor)); + } } } -- 2.39.5