Second cl for verbose workspaces (ability to log certain potentially non-hermetic events that happen as part of repository rules).

Defining representation for Execute events for workspace logging.

In the future:
- Add more events
- Allowing to specify log file rather than dumping to INFO
- Log levels, full or alerts only

RELNOTES: None
PiperOrigin-RevId: 204748436

9 files changed, 267 insertions, 11 deletions

diff --git a/src/BUILD b/src/BUILD
index 5c11f7e4ea..ae5db6ee83 100644
--- a/src/BUILD
+++ b/src/BUILD
@@ -371,6 +371,7 @@ genrule(
     srcs = [
         "//src/main/protobuf:dist_jars",
         "//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:dist_jars",
+        "//src/main/java/com/google/devtools/build/lib/bazel/debug:dist_jars",
         "//src/main/java/com/google/devtools/build/lib/skylarkdebug/proto:dist_jars",
         "@googleapis//:dist_jars",
     ],
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/debug/BUILD b/src/main/java/com/google/devtools/build/lib/bazel/debug/BUILD
index 208d4e1254..ad9343c99f 100644
--- a/src/main/java/com/google/devtools/build/lib/bazel/debug/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/bazel/debug/BUILD
@@ -4,6 +4,8 @@ package(
     default_visibility = ["//src:__subpackages__"],
 )
 
+load("//tools/build_rules:utilities.bzl", "java_library_srcs")
+
 filegroup(
     name = "srcs",
     srcs = glob(["**"]),
@@ -14,10 +16,32 @@ filegroup(
     ],
 )
 
+proto_library(
+    name = "workspace_log_proto",
+    srcs = ["workspace_log.proto"],
+    deps = [],
+)
+
+java_proto_library(
+    name = "workspace_log_java_proto",
+    deps = [":workspace_log_proto"],
+)
+
+java_library_srcs(
+    name = "workspace_log_java_proto_srcs",
+    deps = [":workspace_log_java_proto"],
+)
+
+filegroup(
+    name = "dist_jars",
+    srcs = [":workspace_log_java_proto_srcs"],
+)
+
 java_library(
     name = "workspace-rule-event",
     srcs = ["WorkspaceRuleEvent.java"],
     deps = [
+        ":workspace_log_java_proto",
         "//src/main/java/com/google/devtools/build/lib:events",
     ],
 )
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEvent.java b/src/main/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEvent.java
index 059b08adae..38c9da3e7c 100644
--- a/src/main/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEvent.java
+++ b/src/main/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEvent.java
@@ -13,28 +13,70 @@
 // limitations under the License.
 package com.google.devtools.build.lib.bazel.debug;
 
+import com.google.devtools.build.lib.bazel.debug.proto.WorkspaceLogProtos;
 import com.google.devtools.build.lib.events.ExtendedEventHandler.ProgressLike;
 import com.google.devtools.build.lib.events.Location;
+import java.util.Map;
 
 /** An event to record events happening during workspace rule resolution */
 public final class WorkspaceRuleEvent implements ProgressLike {
-  String location;
-  String description;
+  WorkspaceLogProtos.WorkspaceEvent event;
+
+  public WorkspaceLogProtos.WorkspaceEvent getLogEvent() {
+    return event;
+  }
+
+  private WorkspaceRuleEvent(WorkspaceLogProtos.WorkspaceEvent event) {
+    this.event = event;
+  }
 
   /**
-   * Creates a new WorkspaceRuleEvent with the given description.
+   * Creates a new WorkspaceRuleEvent for an execution event.
    *
    * <p>Note: we will add more granular information as needed.
    */
-  public WorkspaceRuleEvent(Location location, String description) {
-    this.location = location.print();
-    this.description = description;
+  public static WorkspaceRuleEvent newExecuteEvent(
+      Iterable<Object> args,
+      Integer timeout,
+      Map<String, String> commonEnvironment,
+      Map<String, String> customEnvironment,
+      String outputDirectory,
+      boolean quiet,
+      String ruleLabel,
+      Location location) {
+
+    WorkspaceLogProtos.ExecuteEvent.Builder e =
+        WorkspaceLogProtos.ExecuteEvent.newBuilder()
+            .setTimeoutSeconds(timeout.intValue())
+            .setOutputDirectory(outputDirectory)
+            .setQuiet(quiet);
+    if (commonEnvironment != null) {
+      e = e.putAllEnvironment(commonEnvironment);
+    }
+    if (customEnvironment != null) {
+      e = e.putAllEnvironment(customEnvironment);
+    }
+
+    for (Object a : args) {
+      e.addArguments(a.toString());
+    }
+
+    WorkspaceLogProtos.WorkspaceEvent.Builder result =
+        WorkspaceLogProtos.WorkspaceEvent.newBuilder();
+    result = result.setExecuteEvent(e.build());
+    if (location != null) {
+      result = result.setLocation(location.print());
+    }
+    if (ruleLabel != null) {
+      result = result.setRule(ruleLabel);
+    }
+    return new WorkspaceRuleEvent(result.build());
   }
 
   /*
    * @return a message to log for this event
    */
   public String logMessage() {
-    return location + ": " + description;
+    return event.toString();
   }
 }
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/debug/workspace_log.proto b/src/main/java/com/google/devtools/build/lib/bazel/debug/workspace_log.proto
new file mode 100644
index 0000000000..1dea56af9c
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/bazel/debug/workspace_log.proto
@@ -0,0 +1,51 @@
+// Copyright 2018 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+syntax = "proto3";
+
+package workspace_log;
+
+option java_package = "com.google.devtools.build.lib.bazel.debug.proto";
+option java_outer_classname = "WorkspaceLogProtos";
+
+// Information on "Execute" event in repository_ctx.
+message ExecuteEvent {
+  // Command line arguments, with the first one being the command to execute.
+  repeated string arguments = 2;
+
+  // Timeout used for the command
+  int32 timeout_seconds = 3;
+
+  // Environment variables set for the execution. Note that this includes
+  // variables specified by the user (as an input to Execute command),
+  // as well as variables set indirectly through the rule environment
+  map<string, string> environment = 4;
+
+  // True if quiet execution was requested.
+  bool quiet = 5;
+
+  // Directory that would contain the output of the command.
+  string output_directory = 6;
+}
+
+message WorkspaceEvent {
+  // Location in the code (.bzl file) where the event originates.
+  string location = 1;
+
+  // Label of the rule whose evaluation caused this event.
+  string rule = 2;
+
+  oneof event {
+    ExecuteEvent execute_event = 3;
+  }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java b/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
index 476c47c3dd..d52388c595 100644
--- a/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
+++ b/src/main/java/com/google/devtools/build/lib/bazel/repository/skylark/SkylarkRepositoryContext.java
@@ -237,7 +237,16 @@ public class SkylarkRepositoryContext
       boolean quiet,
       Location location)
       throws EvalException, RepositoryFunctionException {
-    WorkspaceRuleEvent w = new WorkspaceRuleEvent(location, "Executing a command.");
+    WorkspaceRuleEvent w =
+        WorkspaceRuleEvent.newExecuteEvent(
+            arguments,
+            timeout,
+            osObject.getEnvironmentVariables(),
+            environment,
+            outputDirectory.getPathString(),
+            quiet,
+            rule.getLabel().toString(),
+            location);
     env.getListener().post(w);
     createDirectory(outputDirectory);
     return SkylarkExecutionResult.builder(osObject.getEnvironmentVariables())
diff --git a/src/test/java/com/google/devtools/build/lib/BUILD b/src/test/java/com/google/devtools/build/lib/BUILD
index 683170e8bd..b1571ea6dd 100644
--- a/src/test/java/com/google/devtools/build/lib/BUILD
+++ b/src/test/java/com/google/devtools/build/lib/BUILD
@@ -40,6 +40,7 @@ filegroup(
         "//src/test/java/com/google/devtools/build/lib/analysis/skylark/annotations/processor:srcs",
         "//src/test/java/com/google/devtools/build/lib/analysis/whitelisting:srcs",
         "//src/test/java/com/google/devtools/build/lib/bazel/repository/cache:srcs",
+        "//src/test/java/com/google/devtools/build/lib/bazel/debug:srcs",
         "//src/test/java/com/google/devtools/build/lib/bazel/repository/downloader:srcs",
         "//src/test/java/com/google/devtools/build/lib/bazel/repository:srcs",
         "//src/test/java/com/google/devtools/build/lib/buildeventservice:srcs",
diff --git a/src/test/java/com/google/devtools/build/lib/bazel/debug/BUILD b/src/test/java/com/google/devtools/build/lib/bazel/debug/BUILD
new file mode 100644
index 0000000000..b6623e611e
--- /dev/null
+++ b/src/test/java/com/google/devtools/build/lib/bazel/debug/BUILD
@@ -0,0 +1,27 @@
+package(
+    default_testonly = 1,
+    default_visibility = ["//src:__subpackages__"],
+)
+
+filegroup(
+    name = "srcs",
+    testonly = 0,
+    srcs = glob(["**"]),
+    visibility = ["//src/test/java/com/google/devtools/build/lib:__pkg__"],
+)
+
+java_test(
+    name = "WorkspaceRuleEventTest",
+    size = "small",
+    srcs = ["WorkspaceRuleEventTest.java"],
+    deps = [
+        "//src/main/java/com/google/devtools/build/lib:events",
+        "//src/main/java/com/google/devtools/build/lib/bazel/debug:workspace-rule-event",
+        "//src/main/java/com/google/devtools/build/lib/bazel/debug:workspace_log_java_proto",
+        "//src/main/java/com/google/devtools/build/lib/vfs:pathfragment",
+        "//third_party:guava",
+        "//third_party:junit4",
+        "//third_party:mockito",
+        "//third_party:truth",
+    ],
+)
diff --git a/src/test/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEventTest.java b/src/test/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEventTest.java
new file mode 100644
index 0000000000..e13de8af9b
--- /dev/null
+++ b/src/test/java/com/google/devtools/build/lib/bazel/debug/WorkspaceRuleEventTest.java
@@ -0,0 +1,101 @@
+// Copyright 2018 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License
+
+package com.google.devtools.build.lib.bazel.debug;
+
+import static com.google.common.truth.Truth.assertThat;
+
+import com.google.common.collect.ImmutableMap;
+import com.google.devtools.build.lib.bazel.debug.proto.WorkspaceLogProtos;
+import com.google.devtools.build.lib.events.Location;
+import com.google.devtools.build.lib.vfs.PathFragment;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.List;
+import java.util.Map;
+import org.junit.Before;
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.junit.runners.JUnit4;
+
+/** Tests handling of WorkspaceRuleEvent */
+@RunWith(JUnit4.class)
+public final class WorkspaceRuleEventTest {
+  static class DummyString {
+    @Override
+    public String toString() {
+      return "dummy string";
+    }
+  }
+
+  static class DummyLocation extends Location {
+    public DummyLocation() {
+      super(10, 20);
+    };
+
+    @Override
+    public PathFragment getPath() {
+      return null;
+    }
+
+    @Override
+    public String print() {
+      return "location being printed";
+    }
+  }
+
+  @Before
+  public void setUp() {}
+
+  @Test
+  public void newExecuteEvent_expectedResult() {
+    // Set up arguments, as a combination of String and SkylarkPath
+    ArrayList<Object> arguments = new ArrayList<>();
+    arguments.add("argument 1");
+    arguments.add(new DummyString());
+
+    Map<String, String> commonEnv = ImmutableMap.of("key1", "val1", "key3", "val3");
+    Map<String, String> customEnv = ImmutableMap.of("key2", "val2!", "key3", "val3!");
+
+    WorkspaceLogProtos.WorkspaceEvent event =
+        WorkspaceRuleEvent.newExecuteEvent(
+                arguments,
+                2042,
+                commonEnv,
+                customEnv,
+                "outputDir",
+                true,
+                "my_rule",
+                new DummyLocation())
+            .getLogEvent();
+
+    List<String> expectedArgs = Arrays.asList("argument 1", "dummy string");
+
+    Map<String, String> expectedEnv =
+        ImmutableMap.of(
+            "key1", "val1",
+            "key2", "val2!",
+            "key3", "val3!");
+
+    assertThat(event.getRule()).isEqualTo("my_rule");
+    assertThat(event.getLocation()).isEqualTo("location being printed");
+
+    WorkspaceLogProtos.ExecuteEvent executeEvent = event.getExecuteEvent();
+    assertThat(executeEvent.getTimeoutSeconds()).isEqualTo(2042);
+    assertThat(executeEvent.getQuiet()).isEqualTo(true);
+    assertThat(executeEvent.getOutputDirectory()).isEqualTo("outputDir");
+    assertThat(executeEvent.getArgumentsList()).isEqualTo(expectedArgs);
+    assertThat(executeEvent.getEnvironmentMap()).isEqualTo(expectedEnv);
+  }
+}
diff --git a/src/test/shell/bazel/bazel_workspaces_test.sh b/src/test/shell/bazel/bazel_workspaces_test.sh
index 49bf897ff9..75ebc78392 100755
--- a/src/test/shell/bazel/bazel_workspaces_test.sh
+++ b/src/test/shell/bazel/bazel_workspaces_test.sh
@@ -50,7 +50,7 @@ ex_repo(name = "repo")
 EOF
 
   bazel build //:test --experimental_workspace_rules_logging=yes &> $TEST_log || fail "could not build //:test"
-  executes=`grep "repos.bzl:2:3: Executing a command." $TEST_log | wc -l`
+  executes=`grep "location: .*repos.bzl:2:3" $TEST_log | wc -l`
   if [ "$executes" -ne "1" ]
   then
     fail "Expected exactly 1 occurrence of the given command, got $executes"
@@ -59,7 +59,7 @@ EOF
   # Cached executions are not replayed
   bazel build //:test --experimental_workspace_rules_logging=yes &> output || fail "could not build //:test"
   cat output &> $TEST_log
-  executes=`grep "repos.bzl:2:3: Executing a command." output | wc -l`
+  executes=`grep "location: .*repos.bzl:2:3" output | wc -l`
   if [ "$executes" -ne "0" ]
   then
     fail "Expected exactly 0 occurrence of the given command, got $executes"
@@ -107,7 +107,7 @@ a_repo(name = "another")
 EOF
 
   bazel build //:test --experimental_workspace_rules_logging=yes &> $TEST_log || fail "could not build //:test"
-  executes=`grep "repos.bzl:2:3: Executing a command." $TEST_log | wc -l`
+  executes=`grep "location: .*repos.bzl:2:3" $TEST_log | wc -l`
   if [ "$executes" -le "2" ]
   then
     fail "Expected at least 2 occurrences of the given command, got $executes"