Skip to content

Commit

Permalink
Refactor metrics logging to all flow through MetricsCollector. It's l…
Browse files Browse the repository at this point in the history
…ess difficult than I realized to go BES first, and it simplifies the code and reduces duplication.

We no longer log some data for non-build-related commands, but I think that's ok.

PiperOrigin-RevId: 354089543
  • Loading branch information
janakdr authored and copybara-github committed Jan 27, 2021
1 parent dfb70ea commit 952184f
Show file tree
Hide file tree
Showing 6 changed files with 100 additions and 60 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -740,10 +740,6 @@ message BuildMetrics {
// This includes any remote cache hits, but excludes
// local action cache hits.
int64 actions_executed = 2;

// Total size of all source files newly read this build. Will not include
// unchanged sources on incremental builds.
int64 source_artifact_bytes_read = 5;
}
ActionSummary action_summary = 1;

Expand Down Expand Up @@ -796,7 +792,36 @@ message BuildMetrics {
// reaches the execution phase.
int32 num_builds = 12;
}

CumulativeMetrics cumulative_metrics = 6;

message ArtifactMetrics {
// Total size of all source files newly read this build. Will not include
// unchanged sources on incremental builds.
int64 source_artifact_bytes_read = 1;
}

ArtifactMetrics artifact_metrics = 7;

// Information about the size and shape of the build graph. Some fields may
// not be populated if Bazel was able to skip steps due to caching.
message BuildGraphMetrics {
// How many configured targets/aspects were in this build.
int32 action_lookup_value_count = 1;
// How many actions belonged to those configured targets/aspects. It may not
// be necessary to execute all of these actions to build the requested
// targets.
int32 action_count = 2;
// How many artifacts are outputs of the above actions.
int32 output_artifact_count = 3;
// How many Skyframe nodes there are in memory at the end of the build. This
// may underestimate the number of nodes when running with memory-saving
// settings or with Skybuild, and may overestimate if there are nodes from
// prior evaluations still in the cache.
int32 post_invocation_skyframe_node_count = 4;
}

BuildGraphMetrics build_graph_metrics = 8;
}

// Event providing additional statistics/logs after completion of the build.
Expand Down
1 change: 1 addition & 0 deletions src/main/java/com/google/devtools/build/lib/metrics/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ java_library(
"//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:build_event_stream_java_proto",
"//src/main/java/com/google/devtools/build/lib/profiler",
"//src/main/java/com/google/devtools/build/lib/skyframe:execution_finished_event",
"//src/main/java/com/google/devtools/build/skyframe:skyframe_graph_stats_event",
"//src/main/java/com/google/devtools/common/options",
"//third_party:guava",
],
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,13 @@
import com.google.common.eventbus.AllowConcurrentEvents;
import com.google.common.eventbus.Subscribe;
import com.google.devtools.build.lib.actions.ActionCompletionEvent;
import com.google.devtools.build.lib.actions.AnalysisGraphStatsEvent;
import com.google.devtools.build.lib.analysis.AnalysisPhaseCompleteEvent;
import com.google.devtools.build.lib.analysis.AnalysisPhaseStartedEvent;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.ActionSummary;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.ArtifactMetrics;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.BuildGraphMetrics;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.CumulativeMetrics;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.MemoryMetrics;
import com.google.devtools.build.lib.buildeventstream.BuildEventStreamProtos.BuildMetrics.PackageMetrics;
Expand All @@ -32,39 +35,44 @@
import com.google.devtools.build.lib.profiler.Profiler;
import com.google.devtools.build.lib.runtime.CommandEnvironment;
import com.google.devtools.build.lib.skyframe.ExecutionFinishedEvent;
import com.google.devtools.build.skyframe.SkyframeGraphStatsEvent;
import java.lang.management.ManagementFactory;
import java.lang.management.MemoryMXBean;
import java.time.Duration;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicLong;

class MetricsCollector {

private final CommandEnvironment env;
private final boolean bepPublishUsedHeapSizePostBuild;
// For ActionSummary.
private final AtomicLong executedActionCount = new AtomicLong();

// For CumulativeMetrics.
private final AtomicInteger numAnalyses;
private final AtomicInteger numBuilds;

private int actionsConstructed;
private int targetsLoaded;
private int targetsConfigured;
private int packagesLoaded;
private long sourceArtifactBytesReadPerBuild;
private long analysisTimeInMs;
private final ActionSummary.Builder actionSummary = ActionSummary.newBuilder();
private final TargetMetrics.Builder targetMetrics = TargetMetrics.newBuilder();
private final PackageMetrics.Builder packageMetrics = PackageMetrics.newBuilder();
private final TimingMetrics.Builder timingMetrics = TimingMetrics.newBuilder();
private final ArtifactMetrics.Builder artifactMetrics = ArtifactMetrics.newBuilder();
private final BuildGraphMetrics.Builder buildGraphMetrics = BuildGraphMetrics.newBuilder();

private MetricsCollector(CommandEnvironment env) {
private MetricsCollector(
CommandEnvironment env, AtomicInteger numAnalyses, AtomicInteger numBuilds) {
this.env = env;
Options options = env.getOptions().getOptions(Options.class);
this.bepPublishUsedHeapSizePostBuild =
options != null && options.bepPublishUsedHeapSizePostBuild;
this.numAnalyses = env.getRuntime().getNumAnalyses();
this.numBuilds = env.getRuntime().getNumBuilds();
this.numAnalyses = numAnalyses;
this.numBuilds = numBuilds;
env.getEventBus().register(this);
}

static void installInEnv(CommandEnvironment env) {
new MetricsCollector(env);
static void installInEnv(
CommandEnvironment env, AtomicInteger numAnalyses, AtomicInteger numBuilds) {
new MetricsCollector(env, numAnalyses, numBuilds);
}

@SuppressWarnings("unused")
Expand All @@ -73,13 +81,24 @@ public synchronized void logAnalysisStartingEvent(AnalysisPhaseStartedEvent even
numAnalyses.getAndIncrement();
}

@SuppressWarnings("unused")
@Subscribe
public void onAnalysisPhaseComplete(AnalysisPhaseCompleteEvent event) {
actionsConstructed = event.getActionsConstructed();
targetsLoaded = event.getTargetsLoaded();
targetsConfigured = event.getTargetsConfigured();
packagesLoaded = event.getPkgManagerStats().getPackagesLoaded();
analysisTimeInMs = event.getTimeInMs();
actionSummary.setActionsCreated(event.getActionsConstructed());
targetMetrics
.setTargetsLoaded(event.getTargetsLoaded())
.setTargetsConfigured(event.getTargetsConfigured());
packageMetrics.setPackagesLoaded(event.getPkgManagerStats().getPackagesLoaded());
timingMetrics.setAnalysisPhaseTimeInMs(event.getTimeInMs());
}

@SuppressWarnings("unused")
@Subscribe
public synchronized void logAnalysisGraphStats(AnalysisGraphStatsEvent event) {
buildGraphMetrics
.setActionLookupValueCount(event.getActionLookupValueCount())
.setActionCount(event.getActionCount())
.setOutputArtifactCount(event.getOutputArtifactCount());
}

@SuppressWarnings("unused")
Expand All @@ -88,6 +107,7 @@ public synchronized void logExecutionStartingEvent(ExecutionStartingEvent event)
numBuilds.getAndIncrement();
}

@SuppressWarnings("unused")
@Subscribe
@AllowConcurrentEvents
public void onActionComplete(ActionCompletionEvent event) {
Expand All @@ -97,31 +117,36 @@ public void onActionComplete(ActionCompletionEvent event) {
@SuppressWarnings("unused")
@Subscribe
public void onExecutionComplete(ExecutionFinishedEvent event) {
this.sourceArtifactBytesReadPerBuild = event.sourceArtifactBytesRead();
artifactMetrics.setSourceArtifactBytesRead(event.sourceArtifactBytesRead());
}

@SuppressWarnings("unused")
@Subscribe
public void onSkyframeGraphStats(SkyframeGraphStatsEvent event) {
buildGraphMetrics.setPostInvocationSkyframeNodeCount(event.getGraphSize());
}

@SuppressWarnings("unused")
@Subscribe
public void onBuildComplete(BuildPrecompleteEvent event) {
env.getEventBus().post(new BuildMetricsEvent(createBuildMetrics()));
}

private BuildMetrics createBuildMetrics() {
return BuildMetrics.newBuilder()
.setActionSummary(createActionSummary())
.setActionSummary(finishActionSummary())
.setMemoryMetrics(createMemoryMetrics())
.setTargetMetrics(createTargetMetrics())
.setPackageMetrics(createPackageMetrics())
.setTimingMetrics(createTimingMetrics())
.setTargetMetrics(targetMetrics.build())
.setPackageMetrics(packageMetrics.build())
.setTimingMetrics(finishTimingMetrics())
.setCumulativeMetrics(createCumulativeMetrics())
.setArtifactMetrics(artifactMetrics.build())
.setBuildGraphMetrics(buildGraphMetrics.build())
.build();
}

private ActionSummary createActionSummary() {
return ActionSummary.newBuilder()
.setActionsCreated(actionsConstructed)
.setActionsExecuted(executedActionCount.get())
.setSourceArtifactBytesRead(sourceArtifactBytesReadPerBuild)
.build();
private ActionSummary finishActionSummary() {
return actionSummary.setActionsExecuted(executedActionCount.get()).build();
}

private MemoryMetrics createMemoryMetrics() {
Expand All @@ -138,35 +163,22 @@ private MemoryMetrics createMemoryMetrics() {
return memoryMetrics.build();
}

private TargetMetrics createTargetMetrics() {
return TargetMetrics.newBuilder()
.setTargetsLoaded(targetsLoaded)
.setTargetsConfigured(targetsConfigured)
.build();
}

private PackageMetrics createPackageMetrics() {
return PackageMetrics.newBuilder().setPackagesLoaded(packagesLoaded).build();
}

private CumulativeMetrics createCumulativeMetrics() {
return CumulativeMetrics.newBuilder()
.setNumAnalyses(numAnalyses.get())
.setNumBuilds(numBuilds.get())
.build();
}

private TimingMetrics createTimingMetrics() {
TimingMetrics.Builder timingMetricsBuilder = TimingMetrics.newBuilder();
private TimingMetrics finishTimingMetrics() {
Duration elapsedWallTime = Profiler.elapsedTimeMaybe();
if (elapsedWallTime != null) {
timingMetricsBuilder.setWallTimeInMs(elapsedWallTime.toMillis());
timingMetrics.setWallTimeInMs(elapsedWallTime.toMillis());
}
Duration cpuTime = Profiler.getProcessCpuTimeMaybe();
if (cpuTime != null) {
timingMetricsBuilder.setCpuTimeInMs(cpuTime.toMillis());
timingMetrics.setCpuTimeInMs(cpuTime.toMillis());
}
timingMetricsBuilder.setAnalysisPhaseTimeInMs(analysisTimeInMs);
return timingMetricsBuilder.build();
return timingMetrics.build();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
import com.google.devtools.common.options.OptionDocumentationCategory;
import com.google.devtools.common.options.OptionEffectTag;
import com.google.devtools.common.options.OptionsBase;
import java.util.concurrent.atomic.AtomicInteger;

/**
* A blaze module that installs metrics instrumentations and issues a {@link BuildMetricsEvent} at
Expand All @@ -41,6 +42,9 @@ public static final class Options extends OptionsBase {
public boolean bepPublishUsedHeapSizePostBuild;
}

private final AtomicInteger numAnalyses = new AtomicInteger();
private final AtomicInteger numBuilds = new AtomicInteger();

@Override
public Iterable<Class<? extends OptionsBase>> getCommandOptions(Command command) {
return "build".equals(command.name()) ? ImmutableList.of(Options.class) : ImmutableList.of();
Expand All @@ -57,7 +61,7 @@ public boolean postsBuildMetricsEvent() {

@Override
public void beforeCommand(CommandEnvironment env) {
MetricsCollector.installInEnv(env);
MetricsCollector.installInEnv(env, numAnalyses, numBuilds);
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -184,8 +184,6 @@ public final class BlazeRuntime implements BugReport.BlazeRuntimeInterface {
private final RetainedHeapLimiter retainedHeapLimiter;
@Nullable private final RepositoryRemoteExecutorFactory repositoryRemoteExecutorFactory;
private final Supplier<Downloader> downloaderSupplier;
private final AtomicInteger numAnalyses = new AtomicInteger(0);
private final AtomicInteger numBuilds = new AtomicInteger(0);

// Workspace state (currently exactly one workspace per server)
private BlazeWorkspace workspace;
Expand Down Expand Up @@ -716,14 +714,6 @@ public Map<String, BlazeCommand> getCommandMap() {
return commandMap;
}

public AtomicInteger getNumAnalyses() {
return numAnalyses;
}

public AtomicInteger getNumBuilds() {
return numBuilds;
}

/** Invokes {@link BlazeModule#blazeShutdown()} on all registered modules. */
public void shutdown() {
try {
Expand Down
8 changes: 8 additions & 0 deletions src/main/java/com/google/devtools/build/skyframe/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,14 @@ java_library(
],
)

java_library(
name = "skyframe_graph_stats_event",
srcs = ["SkyframeGraphStatsEvent.java"],
deps = [
"//src/main/java/com/google/devtools/build/lib/events",
],
)

proto_library(
name = "graph_inconsistency",
srcs = ["graph_inconsistency.proto"],
Expand Down

0 comments on commit 952184f

Please sign in to comment.