diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java index b18fd7da15af11..e29ae7d0caa451 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java @@ -197,7 +197,9 @@ public void writeTraceData(JsonWriter jsonWriter, long profileStartTimeNanos) // Primary outputs are non-mergeable, thus incompatible with slim profiles. jsonWriter.name("out").value(actionTaskData.primaryOutputPath); } - if (actionTaskData.targetLabel != null || actionTaskData.mnemonic != null) { + if (actionTaskData.targetLabel != null + || actionTaskData.mnemonic != null + || actionTaskData.configuration != null) { jsonWriter.name("args"); jsonWriter.beginObject(); if (actionTaskData.targetLabel != null) { @@ -206,6 +208,9 @@ public void writeTraceData(JsonWriter jsonWriter, long profileStartTimeNanos) if (actionTaskData.mnemonic != null) { jsonWriter.name("mnemonic").value(actionTaskData.mnemonic); } + if (actionTaskData.configuration != null) { + jsonWriter.name("configuration").value(actionTaskData.configuration); + } jsonWriter.endObject(); } } @@ -234,6 +239,7 @@ static final class ActionTaskData extends TaskData { @Nullable final String primaryOutputPath; @Nullable final String targetLabel; @Nullable final String mnemonic; + @Nullable final String configuration; ActionTaskData( long threadId, @@ -243,11 +249,13 @@ static final class ActionTaskData extends TaskData { @Nullable String mnemonic, String description, @Nullable String primaryOutputPath, - @Nullable String targetLabel) { + @Nullable String targetLabel, + @Nullable String configuration) { super(threadId, startTimeNanos, durationNanos, eventType, description); this.primaryOutputPath = primaryOutputPath; this.targetLabel = targetLabel; this.mnemonic = mnemonic; + this.configuration = configuration; } } @@ -337,6 +345,7 @@ ImmutableList getSlowestTasks() { private boolean collectTaskHistograms; private boolean includePrimaryOutput; private boolean includeTargetLabel; + private boolean includeConfiguration; private Profiler() { actionCountTimeSeriesRef = new AtomicReference<>(); @@ -444,6 +453,7 @@ public synchronized void start( boolean slimProfile, boolean includePrimaryOutput, boolean includeTargetLabel, + boolean includeConfiguration, boolean collectTaskHistograms, LocalResourceCollector localResourceCollector) throws IOException { @@ -463,6 +473,7 @@ public synchronized void start( this.collectTaskHistograms = collectTaskHistograms; this.includePrimaryOutput = includePrimaryOutput; this.includeTargetLabel = includeTargetLabel; + this.includeConfiguration = includeConfiguration; this.recordAllDurations = recordAllDurations; JsonTraceFileWriter writer = null; @@ -811,7 +822,8 @@ public SilentCloseable profileAction( String mnemonic, String description, String primaryOutput, - String targetLabel) { + String targetLabel, + String configuration) { checkNotNull(description); if (isActive() && isProfiling(type)) { final long startTimeNanos = clock.nanoTime(); @@ -825,7 +837,8 @@ public SilentCloseable profileAction( description, mnemonic, includePrimaryOutput ? primaryOutput : null, - includeTargetLabel ? targetLabel : null); + includeTargetLabel ? targetLabel : null, + includeConfiguration ? configuration : null); } finally { releaseLane(lane); } @@ -835,11 +848,6 @@ public SilentCloseable profileAction( } } - public SilentCloseable profileAction( - ProfilerTask type, String description, String primaryOutput, String targetLabel) { - return profileAction(type, /* mnemonic= */ null, description, primaryOutput, targetLabel); - } - private static final SilentCloseable NOP = () -> {}; private boolean countAction(ProfilerTask type) { @@ -874,7 +882,8 @@ private void completeAction( String description, String mnemonic, @Nullable String primaryOutput, - @Nullable String targetLabel) { + @Nullable String targetLabel, + @Nullable String configuration) { if (isActive()) { long endTimeNanos = clock.nanoTime(); long duration = endTimeNanos - startTimeNanos; @@ -889,7 +898,8 @@ private void completeAction( mnemonic, description, primaryOutput, - targetLabel)); + targetLabel, + configuration)); } } } diff --git a/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java b/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java index 38fd6ebd79ba34..13cf38b3a4f783 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java @@ -44,7 +44,8 @@ public static TraceEvent create( @Nullable ImmutableMap args, @Nullable String primaryOutputPath, @Nullable String targetLabel, - @Nullable String mnemonic) { + @Nullable String mnemonic, + @Nullable String configuration) { return new AutoValue_TraceEvent( category, name, @@ -56,7 +57,8 @@ public static TraceEvent create( args, primaryOutputPath, targetLabel, - mnemonic); + mnemonic, + configuration); } @Nullable @@ -90,6 +92,9 @@ public static TraceEvent create( @Nullable public abstract String mnemonic(); + @Nullable + public abstract String configuration(); + private static TraceEvent createFromJsonReader(JsonReader reader) throws IOException { String category = null; String name = null; @@ -101,6 +106,7 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep String targetLabel = null; String mnemonic = null; String type = null; + String configuration = null; ImmutableMap args = null; reader.beginObject(); @@ -122,6 +128,8 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep targetLabel = target instanceof String ? (String) target : null; Object mnemonicValue = args.get("mnemonic"); mnemonic = mnemonicValue instanceof String ? (String) mnemonicValue : null; + Object configurationValue = args.get("configuration"); + configuration = configurationValue instanceof String ? (String) configurationValue : null; } default -> reader.skipValue(); } @@ -138,7 +146,8 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep args, primaryOutputPath, targetLabel, - mnemonic); + mnemonic, + configuration); } private static ImmutableMap parseMap(JsonReader reader) throws IOException { diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java index 6ba26824b549b3..77eabbf4f819eb 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java @@ -419,6 +419,7 @@ ProfilerStartedEvent initProfiler( commandOptions.slimProfile, commandOptions.includePrimaryOutput, commandOptions.profileIncludeTargetLabel, + commandOptions.profileIncludeTargetConfiguration, commandOptions.alwaysProfileSlowOperations, new CollectLocalResourceUsage( bugReporter, diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java index 1c3460aa35ab19..21c7440249e5d1 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java @@ -257,6 +257,14 @@ public String getTypeDescription() { help = "Includes target label in action events' JSON profile data.") public boolean profileIncludeTargetLabel; + @Option( + name = "experimental_profile_include_target_configuration", + defaultValue = "false", + documentationCategory = OptionDocumentationCategory.LOGGING, + effectTags = {OptionEffectTag.BAZEL_MONITORING}, + help = "Includes target configuration hash in action events' JSON profile data.") + public boolean profileIncludeTargetConfiguration; + @Option( name = "profile", defaultValue = "null", diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java index 07d54b9e4ec0ec..11d3a1f86c9936 100644 --- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java +++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java @@ -1020,7 +1020,8 @@ public ActionStepOrResult run(Environment env) action.getMnemonic(), action.describe(), action.getPrimaryOutput().getExecPathString(), - getOwnerLabelAsString(action))) { + getOwnerLabelAsString(action), + getOwnerConfigurationAsString(action))) { String message = action.getProgressMessage(); if (message != null) { reporter.startTask(null, prependExecPhaseStats(message)); @@ -1089,6 +1090,14 @@ private String getOwnerLabelAsString(Action action) { return ownerLabel.getCanonicalForm(); } + private String getOwnerConfigurationAsString(Action action) { + ActionOwner owner = action.getOwner(); + if (owner == null) { + return ""; + } + return owner.getConfigurationChecksum(); + } + private void notifyActionCompletion( ExtendedEventHandler eventHandler, boolean postActionCompletionEvent) { if (statusReporter != null) { diff --git a/src/test/java/com/google/devtools/build/lib/buildtool/util/BlazeRuntimeWrapper.java b/src/test/java/com/google/devtools/build/lib/buildtool/util/BlazeRuntimeWrapper.java index 8c50607c561df7..c25f6b91032eca 100644 --- a/src/test/java/com/google/devtools/build/lib/buildtool/util/BlazeRuntimeWrapper.java +++ b/src/test/java/com/google/devtools/build/lib/buildtool/util/BlazeRuntimeWrapper.java @@ -413,6 +413,7 @@ private void beforeCommand() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration= */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( runtime.getBugReporter(), diff --git a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java index 531e2c0a7cd24e..06a93d557ecfd9 100644 --- a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java +++ b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java @@ -112,6 +112,7 @@ private ByteArrayOutputStream start(ImmutableSet tasks, Profiler.F /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -140,6 +141,7 @@ private void startUnbuffered(ImmutableSet tasks) throws IOExceptio /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -253,6 +255,7 @@ public void testProfilerRecordingAllEvents() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -339,6 +342,7 @@ public void testProfilerWorkerMetrics() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -378,6 +382,7 @@ public void testProfilerRecordingOnlySlowestEvents() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -511,6 +516,7 @@ public void testProfilerRecordsNothing() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -717,6 +723,7 @@ public long nanoTime() { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -771,6 +778,7 @@ public void write(int b) throws IOException { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -810,6 +818,7 @@ public void write(int b) throws IOException { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -844,6 +853,7 @@ public void testPrimaryOutputForAction() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ true, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -856,7 +866,14 @@ public void testPrimaryOutputForAction() throws Exception { /* collectResourceManagerEstimation= */ false, /* collectPressureStallIndicators= */ false, /* collectSkyframeCounts= */ false)); - try (SilentCloseable c = profiler.profileAction(ProfilerTask.ACTION, "test", "foo.out", "")) { + try (SilentCloseable c = + profiler.profileAction( + ProfilerTask.ACTION, /* mnemonic */ + null, + "test", + "foo.out", + "", /* configuration */ + null)) { profiler.logEvent(ProfilerTask.PHASE, "event1"); } profiler.stop(); @@ -886,6 +903,7 @@ public void testTargetLabelForAction() throws Exception { /* slimProfile= */ false, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ true, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -899,7 +917,13 @@ public void testTargetLabelForAction() throws Exception { /* collectPressureStallIndicators= */ false, /* collectSkyframeCounts= */ false)); try (SilentCloseable c = - profiler.profileAction(ProfilerTask.ACTION, "test", "foo.out", "//foo:bar")) { + profiler.profileAction( + ProfilerTask.ACTION, /* mnemonic */ + null, + "test", + "foo.out", + "//foo:bar", /* configuration */ + null)) { profiler.logEvent(ProfilerTask.PHASE, "event1"); } profiler.stop(); @@ -913,6 +937,51 @@ public void testTargetLabelForAction() throws Exception { .hasSize(1); } + @Test + public void testTargetConfigurationForAction() throws Exception { + ByteArrayOutputStream buffer = new ByteArrayOutputStream(); + + profiler.start( + getAllProfilerTasks(), + buffer, + JSON_TRACE_FILE_FORMAT, + "dummy_output_base", + UUID.randomUUID(), + true, + clock, + clock.nanoTime(), + /* slimProfile= */ false, + /* includePrimaryOutput= */ false, + /* includeTargetLabel= */ false, + /* includeConfiguration */ true, + /* collectTaskHistograms= */ true, + new CollectLocalResourceUsage( + BugReporter.defaultInstance(), + WorkerProcessMetricsCollector.instance(), + ResourceManager.instance(), + InMemoryGraph.create(), + /* collectWorkerDataInProfiler= */ false, + /* collectLoadAverage= */ false, + /* collectSystemNetworkUsage= */ false, + /* collectResourceManagerEstimation= */ false, + /* collectPressureStallIndicators= */ false, + /* collectSkyframeCounts= */ false)); + try (SilentCloseable c = + profiler.profileAction( + ProfilerTask.ACTION, /* mnemonic */ null, "test", "foo.out", "//foo:bar", "012345")) { + profiler.logEvent(ProfilerTask.PHASE, "event1"); + } + profiler.stop(); + + JsonProfile jsonProfile = new JsonProfile(new ByteArrayInputStream(buffer.toByteArray())); + + assertThat( + jsonProfile.getTraceEvents().stream() + .filter(traceEvent -> "012345".equals(traceEvent.configuration())) + .collect(Collectors.toList())) + .hasSize(1); + } + private ByteArrayOutputStream getJsonProfileOutputStream(boolean slimProfile) throws IOException { ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); profiler.start( @@ -927,6 +996,7 @@ private ByteArrayOutputStream getJsonProfileOutputStream(boolean slimProfile) th slimProfile, /* includePrimaryOutput= */ false, /* includeTargetLabel= */ false, + /* includeConfiguration */ false, /* collectTaskHistograms= */ true, new CollectLocalResourceUsage( BugReporter.defaultInstance(), @@ -977,11 +1047,18 @@ public void testSlimProfileSize() throws Exception { public void testProfileMnemonicIncluded() throws Exception { ByteArrayOutputStream buffer = start(getAllProfilerTasks(), JSON_TRACE_FILE_FORMAT); try (SilentCloseable c = - profiler.profileAction(ProfilerTask.ACTION, "without mnemonic", "", "")) { + profiler.profileAction( + ProfilerTask.ACTION, /* mnemonic */ + null, + "without mnemonic", + "", + "", /* configuration */ + null)) { clock.advanceMillis(100); } try (SilentCloseable c = - profiler.profileAction(ProfilerTask.ACTION, "foo", "with mnemonic", "", "")) { + profiler.profileAction( + ProfilerTask.ACTION, "foo", "with mnemonic", "", "", /* configuration */ null)) { clock.advanceMillis(100); } profiler.stop(); @@ -1024,10 +1101,29 @@ public void testActionCacheHitsCounted() throws Exception { // The setup here is one action and one action check taking 200ms (the bucket duration), // another action check for 300ms, so spilling over in the next bucket. try (SilentCloseable c = - profiler.profileAction(ProfilerTask.ACTION_CHECK, "bar action", "with mnemonic", "", "")) { - try (SilentCloseable c2 = profiler.profileAction(ProfilerTask.ACTION, "foo action", "", ""); + profiler.profileAction( + ProfilerTask.ACTION_CHECK, + "bar action", + "with mnemonic", + "", + "", /* configuration */ + null)) { + try (SilentCloseable c2 = + profiler.profileAction( + ProfilerTask.ACTION, /* mnemonic */ + null, + "foo action", + "", + "", /* configuration */ + null); SilentCloseable c3 = - profiler.profileAction(ProfilerTask.ACTION_CHECK, "bar action", "", "")) { + profiler.profileAction( + ProfilerTask.ACTION_CHECK, /* mnemonic */ + null, + "bar action", + "", + "", /* configuration */ + null)) { clock.advanceMillis(200); } clock.advanceMillis(100);