Some additional timing logging for discarding analysis cache, multi group accounting, and artifact conflicts.

--
MOS_MIGRATED_REVID=99217433

2 files changed, 13 insertions, 0 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
index 4d6fffcbd9..c28bcad28d 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
@@ -40,6 +40,7 @@ import com.google.devtools.build.lib.packages.PackageIdentifier;
 import com.google.devtools.build.lib.packages.Preprocessor;
 import com.google.devtools.build.lib.pkgcache.PackageCacheOptions;
 import com.google.devtools.build.lib.pkgcache.PathPackageLocator;
+import com.google.devtools.build.lib.profiler.Profiler;
 import com.google.devtools.build.lib.util.AbruptExitException;
 import com.google.devtools.build.lib.util.Pair;
 import com.google.devtools.build.lib.util.ResourceUsage;
@@ -482,6 +483,7 @@ public final class SequencedSkyframeExecutor extends SkyframeExecutor {
    * recreate them if necessary).
    */
   private void discardAnalysisCache(Collection<ConfiguredTarget> topLevelTargets) {
+    long startTime = Profiler.nanoTimeMaybe();
     lastAnalysisDiscarded = true;
     for (Map.Entry<SkyKey, SkyValue> entry : memoizingEvaluator.getValues().entrySet()) {
       if (!entry.getKey().functionName().equals(SkyFunctions.CONFIGURED_TARGET)) {
@@ -493,6 +495,10 @@ public final class SequencedSkyframeExecutor extends SkyframeExecutor {
         ctValue.clear();
       }
     }
+    long duration = Profiler.nanoTimeMaybe() - startTime;
+    if (duration > 0) {
+      LOG.info("Spent " + (duration / 1000 / 1000) + " ms discarding analysis cache");
+    }
   }
 
   @Override
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
index 601d7ec6bd..45a3849496 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
@@ -80,6 +80,7 @@ import com.google.devtools.build.lib.pkgcache.PackageCacheOptions;
 import com.google.devtools.build.lib.pkgcache.PackageManager;
 import com.google.devtools.build.lib.pkgcache.PathPackageLocator;
 import com.google.devtools.build.lib.pkgcache.TransitivePackageLoader;
+import com.google.devtools.build.lib.profiler.Profiler;
 import com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.ActionCompletedReceiver;
 import com.google.devtools.build.lib.skyframe.SkyframeActionExecutor.ProgressSupplier;
 import com.google.devtools.build.lib.syntax.Label;
@@ -913,9 +914,15 @@ public abstract class SkyframeExecutor implements WalkableGraphFactory {
         || skyframeBuildView.isSomeConfiguredTargetInvalidated()) {
       // This operation is somewhat expensive, so we only do it if the graph might have changed in
       // some way -- either we analyzed a new target or we invalidated an old one.
+      long startTime = Profiler.nanoTimeMaybe();
       skyframeActionExecutor.findAndStoreArtifactConflicts(getActionLookupValues());
       skyframeBuildView.resetEvaluatedConfiguredTargetFlag();
       // The invalidated configured targets flag will be reset later in the evaluate() call.
+
+      long duration = Profiler.nanoTimeMaybe() - startTime;
+      if (duration > 0) {
+        LOG.info("Spent " + (duration / 1000 / 1000) + " ms discovering artifact conflicts");
+      }
     }
     return skyframeActionExecutor.badActions();
   }