Treat DEBUG events as progress-like.

justinhorvitz · copybara-github · commit 6e945e8ab422 · 2022-11-10T14:48:41.000-08:00
The primary source of `DEBUG` events is the starlark `print()` function. The motivation in making this change is to emit `print()` statements more intelligibly, including: * Not deduplicating multiple identical prints from the same line of code. * Not replaying prints when the corresponding skyframe node is cached. For example, we currently replay prints in a `BUILD` file even when the package is up to date and the starlark code is not executed. A secondary benefit is that we don't spend memory retaining `DEBUG` events in skyframe. This change makes `DEBUG` events match the semantics of `INFO` and `PROGRESS` events. See the documentation on `Reportable#storeForReplay`. There is some chance that this causes additional spam or breaks something relying on cached print statements in incremental build output, but per [style guide](https://bazel.build/rules/bzl-style#print-for-debugging), `print()` should not be used for production code anyway. There are a couple other minor sources of `DEBUG` events besides `print()`, and those semantics will be changed as well (for the better, in my opinion). Fixes bazelbuild#16721. RELNOTES: Starlark `print()` statements are now emitted iff the line of code is executed. They are no longer replayed on subsequent invocations unless the Starlark code is re-executed. Additionally, multiple identical `print()` statements (same string from the same line of code, e.g. from a loop) are all emitted and no longer deduplicated. PiperOrigin-RevId: 487645012 Change-Id: I8b13df67febc9f330c864930688bca31c3711276
diff --git a/src/main/java/com/google/devtools/build/lib/events/Event.java b/src/main/java/com/google/devtools/build/lib/events/Event.java
@@ -73,7 +73,7 @@ public void reportTo(ExtendedEventHandler handler) {
 
   @Override
   public boolean storeForReplay() {
-    return kind != EventKind.PROGRESS && kind != EventKind.INFO;
+    return kind != EventKind.PROGRESS && kind != EventKind.INFO && kind != EventKind.DEBUG;
   }
 
   public EventKind getKind() {
diff --git a/src/main/java/com/google/devtools/build/lib/events/Reportable.java b/src/main/java/com/google/devtools/build/lib/events/Reportable.java
@@ -42,8 +42,8 @@ public interface Reportable {
    *
    * <p>Evaluations may disable all event storage and replay by using a custom {@link
    * com.google.devtools.build.skyframe.EventFilter}, in which case this method is only used to
-   * fulfill the semantics of {@link
-   * com.google.devtools.build.skyframe.SkyFunction.Environment#reportEvent}.
+   * fulfill the semantics described at {@link
+   * com.google.devtools.build.skyframe.SkyFunction.Environment#getListener}.
    *
    * <p>This method is not relevant for events which do not originate from {@link
    * com.google.devtools.build.skyframe.SkyFunction} evaluation.
diff --git a/src/test/java/com/google/devtools/build/lib/starlark/StarlarkIntegrationTest.java b/src/test/java/com/google/devtools/build/lib/starlark/StarlarkIntegrationTest.java
@@ -3780,4 +3780,36 @@ public void nonExecutableStarlarkRuleReturningTestEnvironmentProducesAWarning()
             + " non-test target has no effect",
         ImmutableSet.of(EventKind.WARNING));
   }
+
+  @Test
+  public void identicalPrintStatementsOnSameLineNotDeduplicated_buildFileLoop() throws Exception {
+    scratch.file("foo/BUILD", "[print('this is a print statement') for _ in range(2)]");
+    update("//foo:all", /*loadingPhaseThreads=*/ 1, /*doAnalysis=*/ false);
+    assertContainsEventWithFrequency("this is a print statement", 2);
+  }
+
+  @Test
+  public void identicalPrintStatementsOnSameLineNotDeduplicated_macroCalledFromMultipleBuildFiles()
+      throws Exception {
+    scratch.file("defs/BUILD");
+    scratch.file("defs/macro.bzl", "def macro():", "  print('this is a print statement')");
+    scratch.file("foo/BUILD", "load('//defs:macro.bzl', 'macro')", "macro()");
+    scratch.file("bar/BUILD", "load('//defs:macro.bzl', 'macro')", "macro()");
+    update("//...", /*loadingPhaseThreads=*/ 1, /*doAnalysis=*/ false);
+    assertContainsEventWithFrequency("this is a print statement", 2);
+  }
+
+  @Test
+  public void identicalPrintStatementsOnSameLineNotDeduplicated_ruleImplementationFunction()
+      throws Exception {
+    scratch.file(
+        "foo/defs.bzl",
+        "def _my_rule_impl(ctx):",
+        "  print('this is a print statement')",
+        "my_rule = rule(implementation = _my_rule_impl)");
+    scratch.file(
+        "foo/BUILD", "load(':defs.bzl', 'my_rule')", "my_rule(name = 'a')", "my_rule(name = 'b')");
+    update("//foo:all", /*loadingPhaseThreads=*/ 1, /*doAnalysis=*/ true);
+    assertContainsEventWithFrequency("this is a print statement", 2);
+  }
 }
diff --git a/src/test/shell/integration/starlark_configurations_external_workspaces_test.sh b/src/test/shell/integration/starlark_configurations_external_workspaces_test.sh
@@ -228,11 +228,15 @@ EOF
   expect_log "value before transition: prickly-pear"
   expect_log "value after transition: prickly-pear"
 
+  bazel clean 2>"$TEST_log" || fail "Clean failed"
+
   bazel build :my_target --@sub//:my_flag=prickly-pear \
       > output 2>"$TEST_log" || fail "Expected success"
   expect_log "value before transition: prickly-pear"
   expect_log "value after transition: prickly-pear"
 
+  bazel clean 2>"$TEST_log" || fail "Clean failed"
+
   bazel build :my_target --@//:my_flag=prickly-pear \
       > output 2>"$TEST_log" || fail "Expected success"
   expect_log "value before transition: prickly-pear"
diff --git a/src/test/shell/integration/starlark_configurations_test.sh b/src/test/shell/integration/starlark_configurations_test.sh
@@ -173,6 +173,8 @@ function test_multiple_starlark_flags() {
   expect_log "type=coffee"
   expect_log "temp=iced"
 
+  bazel clean 2>"$TEST_log" || fail "Clean failed"
+
   # Ensure that order doesn't matter.
   bazel build //$pkg:my_drink --//$pkg:temp="iced" --//$pkg:type="coffee" \
     > output 2>"$TEST_log" || fail "Expected success"

Original file line number	Diff line number	Diff line change
`@@ -73,7 +73,7 @@ public void reportTo(ExtendedEventHandler handler) {`
`73`	`73`
`74`	`74`	`@Override`
`75`	`75`	`public boolean storeForReplay() {`
`76`		`- return kind != EventKind.PROGRESS && kind != EventKind.INFO;`
	`76`	`+ return kind != EventKind.PROGRESS && kind != EventKind.INFO && kind != EventKind.DEBUG;`
`77`	`77`	`}`
`78`	`78`
`79`	`79`	`public EventKind getKind() {`
Original file line number	Diff line number	Diff line change
`@@ -42,8 +42,8 @@ public interface Reportable {`
`42`	`42`	`*`
`43`	`43`	`* <p>Evaluations may disable all event storage and replay by using a custom {@link`
`44`	`44`	`* com.google.devtools.build.skyframe.EventFilter}, in which case this method is only used to`
`45`		`- * fulfill the semantics of {@link`
`46`		`- * com.google.devtools.build.skyframe.SkyFunction.Environment#reportEvent}.`
	`45`	`+ * fulfill the semantics described at {@link`
	`46`	`+ * com.google.devtools.build.skyframe.SkyFunction.Environment#getListener}.`
`47`	`47`	`*`
`48`	`48`	`* <p>This method is not relevant for events which do not originate from {@link`
`49`	`49`	`* com.google.devtools.build.skyframe.SkyFunction} evaluation.`