Refactoring of SkyFunctionEnvironment to iterate over events/postables only when they're actually being put into a committed value. The previous behavior submitted deps' events twice, when the dep was added and when the node finished building.

The intention is to build on this refactoring to cut off events/postables across the analysis-execution boundary, so that actions are not carrying around nested sets of warnings coming from their configured targets. This will be safe because to execute an action, we must already have analyzed its configured target, so the warning would have been emitted there.

As can be seen from the changed test, this is not a pure behavior no-op. We will now emit cached events slightly later, on value committal, rather than on first dep declaration. This should not be an issue: since the events are cached, the user must have already seen them on a prior build, so the delay should not be important.

Inversely, we now report events slightly more quickly during bubbling up, since we report them at each stage, as opposed to just at ParallelEvaluator evaluation completion.

PiperOrigin-RevId: 208316502

5 files changed, 160 insertions, 76 deletions

diff --git a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
index 315aa8458c..f8f21f254e 100644
--- a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
+++ b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
@@ -513,8 +513,8 @@ public abstract class AbstractExceptionalParallelEvaluator<E extends Exception>
               errorKey,
               ValueWithMetadata.error(
                   ErrorInfo.fromChildErrors(errorKey, ImmutableSet.of(error)),
-                  env.buildEvents(parentEntry, /*expectDoneDeps=*/ false),
-                  env.buildPosts(parentEntry, /*expectDoneDeps=*/ false)));
+                  env.buildAndReportEvents(parentEntry, /*expectDoneDeps=*/ false),
+                  env.buildAndReportPostables(parentEntry, /*expectDoneDeps=*/ false)));
           continue;
         }
       } finally {
@@ -526,8 +526,8 @@ public abstract class AbstractExceptionalParallelEvaluator<E extends Exception>
           errorKey,
           ValueWithMetadata.error(
               ErrorInfo.fromChildErrors(errorKey, ImmutableSet.of(error)),
-              env.buildEvents(parentEntry, /*expectDoneDeps=*/ false),
-              env.buildPosts(parentEntry, /*expectDoneDeps=*/ false)));
+              env.buildAndReportEvents(parentEntry, /*expectDoneDeps=*/ false),
+              env.buildAndReportPostables(parentEntry, /*expectDoneDeps=*/ false)));
     }
 
     // Reset the interrupt bit if there was an interrupt from outside this evaluator interrupt.
diff --git a/src/main/java/com/google/devtools/build/skyframe/SkyFunctionEnvironment.java b/src/main/java/com/google/devtools/build/skyframe/SkyFunctionEnvironment.java
index b5fb94c751..f879a18efd 100644
--- a/src/main/java/com/google/devtools/build/skyframe/SkyFunctionEnvironment.java
+++ b/src/main/java/com/google/devtools/build/skyframe/SkyFunctionEnvironment.java
@@ -264,7 +264,7 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
     Preconditions.checkState(building, skyKey);
   }
 
-  NestedSet<TaggedEvents> buildEvents(NodeEntry entry, boolean expectDoneDeps)
+  NestedSet<TaggedEvents> buildAndReportEvents(NodeEntry entry, boolean expectDoneDeps)
       throws InterruptedException {
     if (!evaluatorContext.getStoredEventFilter().storeEventsAndPosts()) {
       return NestedSetBuilder.emptySet(Order.STABLE_ORDER);
@@ -277,14 +277,17 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
 
     GroupedList<SkyKey> depKeys = entry.getTemporaryDirectDeps();
     Collection<SkyValue> deps =
-        getDepValuesForDoneNodeFromErrorOrDepsOrGraph(depKeys, expectDoneDeps);
+        getDepValuesForDoneNodeFromErrorOrDepsOrGraph(
+            depKeys.getAllElementsAsIterable(), expectDoneDeps, depKeys.numElements());
     for (SkyValue value : deps) {
       eventBuilder.addTransitive(ValueWithMetadata.getEvents(value));
     }
-    return eventBuilder.build();
+    NestedSet<TaggedEvents> result = eventBuilder.build();
+    evaluatorContext.getReplayingNestedSetEventVisitor().visit(result);
+    return result;
   }
 
-  NestedSet<Postable> buildPosts(NodeEntry entry, boolean expectDoneDeps)
+  NestedSet<Postable> buildAndReportPostables(NodeEntry entry, boolean expectDoneDeps)
       throws InterruptedException {
     if (!evaluatorContext.getStoredEventFilter().storeEventsAndPosts()) {
       return NestedSetBuilder.emptySet(Order.STABLE_ORDER);
@@ -294,11 +297,14 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
 
     GroupedList<SkyKey> depKeys = entry.getTemporaryDirectDeps();
     Collection<SkyValue> deps =
-        getDepValuesForDoneNodeFromErrorOrDepsOrGraph(depKeys, expectDoneDeps);
+        getDepValuesForDoneNodeFromErrorOrDepsOrGraph(
+            depKeys.getAllElementsAsIterable(), expectDoneDeps, depKeys.numElements());
     for (SkyValue value : deps) {
       postBuilder.addTransitive(ValueWithMetadata.getPosts(value));
     }
-    return postBuilder.build();
+    NestedSet<Postable> result = postBuilder.build();
+    evaluatorContext.getReplayingNestedSetPostableVisitor().visit(result);
+    return result;
   }
 
   void setValue(SkyValue newValue) {
@@ -415,8 +421,7 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
    * <p>If {@code assertDone}, this asserts that all deps in {@code depKeys} are done.
    */
   private Collection<SkyValue> getDepValuesForDoneNodeFromErrorOrDepsOrGraph(
-      GroupedList<SkyKey> depKeys, boolean assertDone) throws InterruptedException {
-    int keySize = depKeys.numElements();
+      Iterable<SkyKey> depKeys, boolean assertDone, int keySize) throws InterruptedException {
     List<SkyValue> result = new ArrayList<>(keySize);
     // depKeys may contain keys in newlyRegisteredDeps whose values have not yet been retrieved from
     // the graph during this environment's lifetime.
@@ -424,7 +429,7 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
     ArrayList<SkyKey> missingKeys =
         expectedMissingKeys > 0 ? new ArrayList<>(expectedMissingKeys) : null;
 
-    for (SkyKey key : depKeys.getAllElementsAsIterable()) {
+    for (SkyKey key : depKeys) {
       SkyValue value = maybeGetValueFromErrorOrDeps(key);
       if (value == null) {
         if (key == ErrorTransienceValue.KEY) {
@@ -556,12 +561,6 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
 
       if (!previouslyRequestedDepsValues.containsKey(depKey)) {
         newlyRequestedDeps.add(depKey);
-        evaluatorContext
-            .getReplayingNestedSetPostableVisitor()
-            .visit(ValueWithMetadata.getPosts(depValue));
-        evaluatorContext
-            .getReplayingNestedSetEventVisitor()
-            .visit(ValueWithMetadata.getEvents(depValue));
       }
     }
     newlyRequestedDeps.endGroup();
@@ -708,8 +707,8 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
     // (2) value == null && enqueueParents happens for values that are found to have errors
     // during a --keep_going build.
 
-    NestedSet<Postable> posts = buildPosts(primaryEntry, /*expectDoneDeps=*/ true);
-    NestedSet<TaggedEvents> events = buildEvents(primaryEntry, /*expectDoneDeps=*/ true);
+    NestedSet<Postable> posts = buildAndReportPostables(primaryEntry, /*expectDoneDeps=*/ true);
+    NestedSet<TaggedEvents> events = buildAndReportEvents(primaryEntry, /*expectDoneDeps=*/ true);
 
     SkyValue valueWithMetadata;
     if (value == null) {
@@ -780,8 +779,6 @@ class SkyFunctionEnvironment extends AbstractSkyFunctionEnvironment {
     evaluatorContext.signalValuesAndEnqueueIfReady(
         skyKey, reverseDeps, currentVersion, enqueueParents);
 
-    evaluatorContext.getReplayingNestedSetPostableVisitor().visit(posts);
-    evaluatorContext.getReplayingNestedSetEventVisitor().visit(events);
     return enqueueParents == EnqueueParentBehavior.ENQUEUE ? null : reverseDeps;
   }
 
diff --git a/src/test/java/com/google/devtools/build/skyframe/DeterministicHelper.java b/src/test/java/com/google/devtools/build/skyframe/DeterministicHelper.java
index 524ea9b098..d9e125b54d 100644
--- a/src/test/java/com/google/devtools/build/skyframe/DeterministicHelper.java
+++ b/src/test/java/com/google/devtools/build/skyframe/DeterministicHelper.java
@@ -145,5 +145,12 @@ public class DeterministicHelper extends NotifyingHelper {
       result.addAll(super.getInProgressReverseDeps());
       return result;
     }
+
+    @Override
+    public Set<SkyKey> setValue(SkyValue value, Version version) throws InterruptedException {
+      TreeSet<SkyKey> result = new TreeSet<>(ALPHABETICAL_SKYKEY_COMPARATOR);
+      result.addAll(super.setValue(value, version));
+      return result;
+    }
   }
 }
diff --git a/src/test/java/com/google/devtools/build/skyframe/MemoizingEvaluatorTest.java b/src/test/java/com/google/devtools/build/skyframe/MemoizingEvaluatorTest.java
index dc28c772aa..3fc2e27ff7 100644
--- a/src/test/java/com/google/devtools/build/skyframe/MemoizingEvaluatorTest.java
+++ b/src/test/java/com/google/devtools/build/skyframe/MemoizingEvaluatorTest.java
@@ -38,7 +38,6 @@ import com.google.common.util.concurrent.Uninterruptibles;
 import com.google.devtools.build.lib.events.DelegatingEventHandler;
 import com.google.devtools.build.lib.events.Event;
 import com.google.devtools.build.lib.events.EventCollector;
-import com.google.devtools.build.lib.events.EventKind;
 import com.google.devtools.build.lib.events.ExtendedEventHandler;
 import com.google.devtools.build.lib.events.Reporter;
 import com.google.devtools.build.lib.testutil.TestThread;
@@ -659,6 +658,60 @@ public class MemoizingEvaluatorTest {
   }
 
   @Test
+  public void depMessageBeforeNodeMessageOrNodeValue() throws Exception {
+    SkyKey top = skyKey("top");
+    AtomicBoolean depWarningEmitted = new AtomicBoolean(false);
+    injectGraphListenerForTesting(
+        (key, type, order, context) -> {
+          if (key.equals(top) && type == EventType.SET_VALUE) {
+            assertThat(depWarningEmitted.get()).isTrue();
+          }
+        },
+        /*deterministic=*/ false);
+    String depWarning = "dep warning";
+    Event topWarning = Event.warn("top warning");
+    reporter =
+        new DelegatingEventHandler(reporter) {
+          @Override
+          public void handle(Event e) {
+            if (e.getMessage().equals(depWarning)) {
+              depWarningEmitted.set(true);
+            }
+            if (e.equals(topWarning)) {
+              assertThat(depWarningEmitted.get()).isTrue();
+            }
+            super.handle(e);
+          }
+        };
+    SkyKey leaf = skyKey("leaf");
+    tester.getOrCreate(leaf).setWarning(depWarning).setConstantValue(new StringValue("leaf"));
+    tester
+        .getOrCreate(top)
+        .setBuilder(
+            new NoExtractorFunction() {
+              @Nullable
+              @Override
+              public SkyValue compute(SkyKey skyKey, Environment env) throws InterruptedException {
+                SkyValue depValue = env.getValue(leaf);
+                if (depValue != null) {
+                  // Default GraphTester implementation warns before requesting deps, which doesn't
+                  // work
+                  // for ordering assertions with memoizing evaluator subclsses that don't store
+                  // events
+                  // and instead just pass them through directly. By warning after the dep is done
+                  // we
+                  // avoid that issue.
+                  env.getListener().handle(topWarning);
+                }
+                return depValue;
+              }
+            });
+    EvaluationResult<StringValue> result = tester.eval(/*keepGoing=*/ false, top);
+    assertThatEvaluationResult(result).hasEntryThat(top).isEqualTo(new StringValue("leaf"));
+    assertThatEvents(eventCollector).containsExactly(depWarning, topWarning.getMessage()).inOrder();
+  }
+
+  @Test
   public void invalidationWithChangeAndThenNothingChanged() throws Exception {
     SkyKey bKey = GraphTester.nonHermeticKey("b");
     tester.getOrCreate("a").addDependency(bKey).setComputedValue(COPY);
@@ -2079,46 +2132,66 @@ public class MemoizingEvaluatorTest {
   private void dirtyChildEnqueuesParentDuringCheckDependencies(final boolean throwError)
       throws Exception {
     // Value to be built. It will be signaled to rebuild before it has finished checking its deps.
-    final SkyKey top = GraphTester.toSkyKey("top");
+    final SkyKey top = GraphTester.toSkyKey("a_top");
+    // otherTop is alphabetically after top.
+    SkyKey otherTop = skyKey("z_otherTop");
     // Dep that blocks before it acknowledges being added as a dep by top, so the firstKey value has
     // time to signal top. (Importantly its key is alphabetically after 'firstKey').
     final SkyKey slowAddingDep = GraphTester.toSkyKey("slowDep");
+    // Value that is modified on the second build. Its thread won't finish until it signals top,
+    // which will wait for the signal before it enqueues its next dep. We prevent the thread from
+    // finishing by having the graph listener block on the second reverse dep to signal.
+    SkyKey firstKey = GraphTester.nonHermeticKey("first");
+    tester.set(firstKey, new StringValue("biding"));
     // Don't perform any blocking on the first build.
     final AtomicBoolean delayTopSignaling = new AtomicBoolean(false);
     final CountDownLatch topSignaled = new CountDownLatch(1);
-    final CountDownLatch topRestartedBuild = new CountDownLatch(1);
+    final CountDownLatch topRequestedDepOrRestartedBuild = new CountDownLatch(1);
+    final CountDownLatch parentsRequested = new CountDownLatch(2);
     injectGraphListenerForTesting(
-        new Listener() {
-          @Override
-          public void accept(SkyKey key, EventType type, Order order, @Nullable Object context) {
-            if (!delayTopSignaling.get()) {
-              return;
-            }
-            if (key.equals(top) && type == EventType.SIGNAL && order == Order.AFTER) {
-              // top is signaled by firstKey (since slowAddingDep is blocking), so slowAddingDep
-              // is now free to acknowledge top as a parent.
-              topSignaled.countDown();
-              return;
-            }
-            if (key.equals(slowAddingDep)
-                && type == EventType.ADD_REVERSE_DEP
-                && top.equals(context)
-                && order == Order.BEFORE) {
-              // If top is trying to declare a dep on slowAddingDep, wait until firstKey has
-              // signaled top. Then this add dep will return DONE and top will be signaled,
-              // making it ready, so it will be enqueued.
-              TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
-                  topSignaled, "first key didn't signal top in time");
+        (key, type, order, context) -> {
+          if (!delayTopSignaling.get()) {
+            return;
+          }
+          if (key.equals(otherTop) && type == EventType.SIGNAL) {
+            TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
+                topRequestedDepOrRestartedBuild, "top's builder did not start in time");
+            return;
+          }
+          if (key.equals(firstKey) && type == EventType.ADD_REVERSE_DEP && order == Order.AFTER) {
+            parentsRequested.countDown();
+            return;
+          }
+          if (key.equals(firstKey) && type == EventType.CHECK_IF_DONE && order == Order.AFTER) {
+            parentsRequested.countDown();
+            if (throwError) {
+              topRequestedDepOrRestartedBuild.countDown();
             }
+            return;
+          }
+          if (key.equals(top) && type == EventType.SIGNAL && order == Order.AFTER) {
+            // top is signaled by firstKey (since slowAddingDep is blocking), so slowAddingDep
+            // is now free to acknowledge top as a parent.
+            topSignaled.countDown();
+            return;
+          }
+          if (key.equals(firstKey) && type == EventType.SET_VALUE && order == Order.BEFORE) {
+            // Make sure both parents add themselves as rdeps.
+            TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
+                parentsRequested, "parents did not request dep in time");
+          }
+          if (key.equals(slowAddingDep)
+              && type == EventType.CHECK_IF_DONE
+              && top.equals(context)
+              && order == Order.BEFORE) {
+            // If top is trying to declare a dep on slowAddingDep, wait until firstKey has
+            // signaled top. Then this add dep will return DONE and top will be signaled,
+            // making it ready, so it will be enqueued.
+            TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
+                topSignaled, "first key didn't signal top in time");
           }
         },
         /*deterministic=*/ true);
-    // Value that is modified on the second build. Its thread won't finish until it signals top,
-    // which will wait for the signal before it enqueues its next dep. We prevent the thread from
-    // finishing by having the listener to which it reports its warning block until top's builder
-    // starts.
-    SkyKey firstKey = GraphTester.nonHermeticKey("first");
-    tester.set(firstKey, new StringValue("biding"));
     tester.set(slowAddingDep, new StringValue("dep"));
     final AtomicInteger numTopInvocations = new AtomicInteger(0);
     tester
@@ -2130,9 +2203,9 @@ public class MemoizingEvaluatorTest {
                   throws InterruptedException {
                 numTopInvocations.incrementAndGet();
                 if (delayTopSignaling.get()) {
-                  // The reporter will be given firstKey's warning to emit when it is requested as a dep
-                  // below, if firstKey is already built, so we release the reporter's latch beforehand.
-                  topRestartedBuild.countDown();
+                  // The graph listener will block on firstKey's signaling of otherTop above until
+                  // this thread starts running.
+                  topRequestedDepOrRestartedBuild.countDown();
                 }
                 // top's builder just requests both deps in a group.
                 env.getValuesOrThrow(
@@ -2140,31 +2213,37 @@ public class MemoizingEvaluatorTest {
                 return env.valuesMissing() ? null : new StringValue("top");
               }
             });
-    reporter =
-        new DelegatingEventHandler(reporter) {
-          @Override
-          public void handle(Event e) {
-            super.handle(e);
-            if (e.getKind() == EventKind.WARNING) {
-              if (!throwError) {
-                TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
-                    topRestartedBuild, "top's builder did not start in time");
-              }
-            }
-          }
-        };
     // First build : just prime the graph.
     EvaluationResult<StringValue> result = tester.eval(/*keepGoing=*/false, top);
     assertThat(result.hasError()).isFalse();
     assertThat(result.get(top)).isEqualTo(new StringValue("top"));
     assertThat(numTopInvocations.get()).isEqualTo(2);
     // Now dirty the graph, and maybe have firstKey throw an error.
-    String warningText = "warning text";
-    tester.getOrCreate(firstKey, /*markAsModified=*/true).setHasError(throwError)
-        .setWarning(warningText);
+    if (throwError) {
+      tester
+          .getOrCreate(firstKey, /*markAsModified=*/ true)
+          .setConstantValue(null)
+          .setBuilder(
+              new NoExtractorFunction() {
+                @Nullable
+                @Override
+                public SkyValue compute(SkyKey skyKey, Environment env)
+                    throws SkyFunctionException {
+                  TrackingAwaiter.INSTANCE.awaitLatchAndTrackExceptions(
+                      parentsRequested, "both parents didn't request in time");
+                  throw new GenericFunctionException(
+                      new SomeErrorException(firstKey.toString()), Transience.PERSISTENT);
+                }
+              });
+    } else {
+      tester
+          .getOrCreate(firstKey, /*markAsModified=*/ true)
+          .setConstantValue(new StringValue("new"));
+    }
+    tester.getOrCreate(otherTop).addDependency(firstKey).setComputedValue(CONCATENATE);
     tester.invalidate();
     delayTopSignaling.set(true);
-    result = tester.eval(/*keepGoing=*/false, top);
+    result = tester.eval(/*keepGoing=*/ false, top, otherTop);
     if (throwError) {
       assertThat(result.hasError()).isTrue();
       assertThat(result.keyNames()).isEmpty(); // No successfully evaluated values.
@@ -2184,9 +2263,8 @@ public class MemoizingEvaluatorTest {
           .that(numTopInvocations.get())
           .isEqualTo(3);
     }
-    assertThatEvents(eventCollector).containsExactly(warningText);
     assertThat(topSignaled.getCount()).isEqualTo(0);
-    assertThat(topRestartedBuild.getCount()).isEqualTo(0);
+    assertThat(topRequestedDepOrRestartedBuild.getCount()).isEqualTo(0);
   }
 
   @Test
diff --git a/src/test/java/com/google/devtools/build/skyframe/NotifyingHelper.java b/src/test/java/com/google/devtools/build/skyframe/NotifyingHelper.java
index c24f54e418..35d2c70e82 100644
--- a/src/test/java/com/google/devtools/build/skyframe/NotifyingHelper.java
+++ b/src/test/java/com/google/devtools/build/skyframe/NotifyingHelper.java
@@ -309,7 +309,9 @@ public class NotifyingHelper {
     public DependencyState checkIfDoneForDirtyReverseDep(SkyKey reverseDep)
         throws InterruptedException {
       graphListener.accept(myKey, EventType.CHECK_IF_DONE, Order.BEFORE, reverseDep);
-      return super.checkIfDoneForDirtyReverseDep(reverseDep);
+      DependencyState dependencyState = super.checkIfDoneForDirtyReverseDep(reverseDep);
+      graphListener.accept(myKey, EventType.CHECK_IF_DONE, Order.AFTER, reverseDep);
+      return dependencyState;
     }
 
     @Override