Skip to content

Commit

Permalink
Treat DEBUG events as progress-like. (bazelbuild#16762)
Browse files Browse the repository at this point in the history
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

Co-authored-by: Googler <[email protected]>
  • Loading branch information
ShreeM01 and justinhorvitz authored Nov 14, 2022
1 parent e5f92a4 commit 3bda5c9
Show file tree
Hide file tree
Showing 5 changed files with 41 additions and 3 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down
2 changes: 2 additions & 0 deletions src/test/shell/integration/starlark_configurations_test.sh
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down

0 comments on commit 3bda5c9

Please sign in to comment.