diff options
7 files changed, 136 insertions, 2 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildEventId.java b/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildEventId.java index 2479b59b3d..7e582a5794 100644 --- a/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildEventId.java +++ b/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildEventId.java @@ -273,4 +273,12 @@ public final class BuildEventId implements Serializable { return new BuildEventId( BuildEventStreamProtos.BuildEventId.newBuilder().setBuildFinished(finishedId).build()); } + + public static BuildEventId buildToolLogs() { + return new BuildEventId( + BuildEventStreamProtos.BuildEventId.newBuilder() + .setBuildToolLogs( + BuildEventStreamProtos.BuildEventId.BuildToolLogsId.getDefaultInstance()) + .build()); + } } diff --git a/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildToolLogs.java b/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildToolLogs.java new file mode 100644 index 0000000000..23e1b07e53 --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/buildeventstream/BuildToolLogs.java @@ -0,0 +1,69 @@ +// Copyright 2017 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.buildeventstream; + +import com.google.common.collect.ImmutableList; +import com.google.devtools.build.lib.util.Pair; +import com.google.devtools.build.lib.vfs.Path; +import com.google.protobuf.ByteString; +import java.nio.charset.StandardCharsets; +import java.util.Collection; + +/** Event reporting on statistics about the build. */ +public class BuildToolLogs implements BuildEventWithOrderConstraint { + private final Collection<Pair<String, String>> directValues; + private final Collection<Pair<String, Path>> logFiles; + + public BuildToolLogs( + Collection<Pair<String, String>> directValues, Collection<Pair<String, Path>> logFiles) { + this.directValues = directValues; + this.logFiles = logFiles; + } + + @Override + public BuildEventId getEventId() { + return BuildEventId.buildToolLogs(); + } + + @Override + public Collection<BuildEventId> getChildrenEvents() { + return ImmutableList.<BuildEventId>of(); + } + + @Override + public BuildEventStreamProtos.BuildEvent asStreamProto(BuildEventConverters converters) { + BuildEventStreamProtos.BuildToolLogs.Builder toolLogs = + BuildEventStreamProtos.BuildToolLogs.newBuilder(); + for (Pair<String, String> direct : directValues) { + toolLogs.addLog( + BuildEventStreamProtos.File.newBuilder() + .setName(direct.getFirst()) + .setContents(ByteString.copyFrom(direct.getSecond().getBytes(StandardCharsets.UTF_8))) + .build()); + } + for (Pair<String, Path> logFile : logFiles) { + toolLogs.addLog( + BuildEventStreamProtos.File.newBuilder() + .setName(logFile.getFirst()) + .setUri(converters.pathConverter().apply(logFile.getSecond())) + .build()); + } + return GenericBuildEvent.protoChaining(this).setBuildToolLogs(toolLogs.build()).build(); + } + + @Override + public Collection<BuildEventId> postedAfter() { + return ImmutableList.of(BuildEventId.buildFinished()); + } +} diff --git a/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto b/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto index 22a5761d49..6b15e27180 100644 --- a/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto +++ b/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto @@ -174,6 +174,11 @@ message BuildEventId { message BuildFinishedId { } + // Identifier of an event providing additional logs/statistics after + // completion of the build. + message BuildToolLogsId { + } + oneof id { UnknownBuildEventId unknown = 1; ProgressId progress = 2; @@ -194,6 +199,7 @@ message BuildEventId { TestResultId test_result = 8; TestSummaryId test_summary = 7; BuildFinishedId build_finished = 9; + BuildToolLogsId build_tool_logs = 20; } } @@ -544,6 +550,11 @@ message BuildFinished { int64 finish_time_millis = 2; } +// Event providing additional statistics/logs after completion of the build. +message BuildToolLogs { + repeated File log = 1; +} + // Message describing a build event. Events will have an identifier that // is unique within a given build invocation; they also announce follow-up // events as children. More details, which are specific to the kind of event @@ -572,5 +583,6 @@ message BuildEvent { TestResult test_result = 10; TestSummary test_summary = 9; BuildFinished finished = 14; + BuildToolLogs build_tool_logs = 23; }; } diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java index 32a2ba98e5..d81542726b 100644 --- a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java +++ b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java @@ -16,6 +16,7 @@ package com.google.devtools.build.lib.buildtool; import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Stopwatch; import com.google.common.base.Throwables; +import com.google.common.collect.ImmutableList; import com.google.devtools.build.lib.actions.BuildFailedException; import com.google.devtools.build.lib.actions.TestExecException; import com.google.devtools.build.lib.analysis.AnalysisPhaseCompleteEvent; @@ -585,7 +586,8 @@ public final class BuildTool { result.setExitCondition(exitCondition); // The stop time has to be captured before we send the BuildCompleteEvent. result.setStopTime(runtime.getClock().currentTimeMillis()); - env.getEventBus().post(new BuildCompleteEvent(result)); + env.getEventBus() + .post(new BuildCompleteEvent(result, ImmutableList.of(BuildEventId.buildToolLogs()))); } private void reportTargets(AnalysisResult analysisResult) { diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/buildevent/TestingCompleteEvent.java b/src/main/java/com/google/devtools/build/lib/buildtool/buildevent/TestingCompleteEvent.java index 282715b015..27f69fd459 100644 --- a/src/main/java/com/google/devtools/build/lib/buildtool/buildevent/TestingCompleteEvent.java +++ b/src/main/java/com/google/devtools/build/lib/buildtool/buildevent/TestingCompleteEvent.java @@ -14,7 +14,9 @@ package com.google.devtools.build.lib.buildtool.buildevent; +import com.google.common.collect.ImmutableList; import com.google.devtools.build.lib.buildeventstream.BuildCompletingEvent; +import com.google.devtools.build.lib.buildeventstream.BuildEventId; import com.google.devtools.build.lib.util.ExitCode; /** @@ -31,6 +33,6 @@ public class TestingCompleteEvent extends BuildCompletingEvent { * @param finishTimeMillis the finish time in milliseconds since the epoch. */ public TestingCompleteEvent(ExitCode exitCode, long finishTimeMillis) { - super(exitCode, finishTimeMillis); + super(exitCode, finishTimeMillis, ImmutableList.of(BuildEventId.buildToolLogs())); } } diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java b/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java index f61d83398e..d5a8750299 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java @@ -14,8 +14,10 @@ package com.google.devtools.build.lib.runtime; import com.google.common.base.Joiner; +import com.google.common.collect.ImmutableList; import com.google.common.eventbus.EventBus; import com.google.common.eventbus.Subscribe; +import com.google.devtools.build.lib.buildeventstream.BuildToolLogs; import com.google.devtools.build.lib.buildtool.BuildRequest; import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent; import com.google.devtools.build.lib.buildtool.buildevent.ExecutionStartingEvent; @@ -26,6 +28,7 @@ import com.google.devtools.build.lib.exec.ExecutionOptions; import com.google.devtools.build.lib.exec.ExecutorBuilder; import com.google.devtools.build.lib.profiler.Profiler; import com.google.devtools.build.lib.profiler.ProfilerTask; +import com.google.devtools.build.lib.util.Pair; import java.util.ArrayList; import java.util.List; import java.util.logging.Logger; @@ -75,14 +78,18 @@ public class BuildSummaryStatsModule extends BlazeModule { public void buildComplete(BuildCompleteEvent event) { try { // We might want to make this conditional on a flag; it can sometimes be a bit of a nuisance. + List<Pair<String, String>> statistics = new ArrayList<>(); List<String> items = new ArrayList<>(); items.add(String.format("Elapsed time: %.3fs", event.getResult().getElapsedSeconds())); + statistics.add( + Pair.of("elapsed time", String.format("%f", event.getResult().getElapsedSeconds()))); if (criticalPathComputer != null) { Profiler.instance().startTask(ProfilerTask.CRITICAL_PATH, "Critical path"); AggregatedCriticalPath<SimpleCriticalPathComponent> criticalPath = criticalPathComputer.aggregate(); items.add(criticalPath.toStringSummary()); + statistics.add(Pair.of("critical path", criticalPath.toString())); logger.info(criticalPath.toString()); logger.info( "Slowest actions:\n " @@ -102,6 +109,7 @@ public class BuildSummaryStatsModule extends BlazeModule { } reporter.handle(Event.info(Joiner.on(", ").join(items))); + reporter.post(new BuildToolLogs(statistics, ImmutableList.of())); } finally { criticalPathComputer = null; } diff --git a/src/test/shell/integration/build_event_stream_test.sh b/src/test/shell/integration/build_event_stream_test.sh index edebf945c3..08b80c2f33 100755 --- a/src/test/shell/integration/build_event_stream_test.sh +++ b/src/test/shell/integration/build_event_stream_test.sh @@ -241,7 +241,9 @@ function test_basic() { expect_log 'build_finished' expect_log 'SUCCESS' expect_log 'finish_time' + expect_log_once 'last_message: true' expect_not_log 'aborted' + expect_log_once '^build_tool_logs' # Target kind for the sh_test expect_log 'target_kind:.*sh' @@ -305,6 +307,8 @@ function test_suite() { || fail "bazel test failed" expect_log 'pkg:true' expect_not_log 'aborted' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_test_summary() { @@ -333,6 +337,8 @@ function test_test_inidivual_results() { expect_log 'status.*PASSED' expect_log_once '^test_summary ' expect_not_log 'aborted' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_test_attempts() { @@ -451,6 +457,8 @@ function test_extra_action() { --experimental_action_listener=pkg:listener \ pkg:output_files_and_tags || fail "bazel build with listener failed" expect_log '^action' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_action_ids() { @@ -482,6 +490,8 @@ function test_aspect_artifacts() { expect_not_log 'aborted' count=`grep '^configured' "${TEST_log}" | wc -l` [ "${count}" -eq 2 ] || fail "Expected 2 configured events, found $count." + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_failing_aspect() { @@ -491,6 +501,8 @@ function test_failing_aspect() { pkg:output_files_and_tags && fail "expected failure") || true expect_log 'aspect.*failing_aspect' expect_log '^finished' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_build_only() { @@ -505,6 +517,8 @@ function test_build_only() { expect_log 'build_finished' expect_log 'finish_time' expect_log 'SUCCESS' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_query() { @@ -523,6 +537,7 @@ function test_query() { expect_log '//pkg:slow' expect_log '^finished' expect_log 'name: "SUCCESS"' + expect_log 'last_message: true' } function test_command_whitelisting() { @@ -578,6 +593,8 @@ function test_root_cause_early() { local ncomplete=`grep -n '^completed' $TEST_log | cut -f 1 -d :` [ $naction -lt $ncomplete ] \ || fail "failed action not before completed target" + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_action_conf() { @@ -602,6 +619,8 @@ function test_loading_failure() { expect_log_once 'reason: LOADING_FAILURE' expect_log 'description.*BUILD file not found on package path' expect_not_log 'expanded' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_visibility_failure() { @@ -616,6 +635,8 @@ function test_visibility_failure() { //visibility:cannotsee && fail "build failure expected") || true expect_log_once 'reason: ANALYSIS_FAILURE' expect_log_once '^aborted' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_loading_failure_keep_going() { @@ -626,6 +647,8 @@ function test_loading_failure_keep_going() { expect_log_once 'reason: LOADING_FAILURE' expect_log_once '^expanded' expect_log 'description.*BUILD file not found on package path' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } # TODO(aehlig): readd, once we stop reporting the important artifacts @@ -665,6 +688,8 @@ function test_srcfiles() { expect_log 'SUCCESS' expect_log_once '^configuration' expect_not_log 'aborted' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_test_fails_to_build() { @@ -673,6 +698,8 @@ function test_test_fails_to_build() { expect_not_log '^test_summary' expect_log 'last_message: true' expect_log 'BUILD_FAILURE' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_no_tests_found() { @@ -681,6 +708,8 @@ function test_no_tests_found() { expect_not_log '^test_summary' expect_log 'last_message: true' expect_log 'NO_TESTS_FOUND' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_no_tests_found_build_failure() { @@ -690,6 +719,8 @@ function test_no_tests_found_build_failure() { expect_log 'last_message: true' expect_log 'yet testing was requested' expect_log 'BUILD_FAILURE' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_alias() { @@ -792,6 +823,8 @@ function test_noanalyze() { || fail "build failed" expect_log_once '^aborted' expect_log 'reason: NO_ANALYZE' + expect_log 'last_message: true' + expect_log_once '^build_tool_logs' } function test_nobuild() { |