aboutsummaryrefslogtreecommitdiffhomepage
diff options
context:
space:
mode:
authorGravatar janakr <janakr@google.com>2018-04-01 19:12:26 -0700
committerGravatar Copybara-Service <copybara-piper@google.com>2018-04-01 19:14:01 -0700
commit52859b454b4426e98d3106c95e5b16e56b5cd437 (patch)
treee7e44cb27fa06fb553ed904a2bb14ea60f86e4a8
parentf54d7e5293cc40ce3507a9adef530e46ab817585 (diff)
Change profiling to only accept strings for its "description" argument. Profiling can hold onto objects for the duration of the build, and some of those objects may be temporary that should not be persisted. In particular, UnixGlob and its inner classes should not outlive loading and analysis. For the most part, care was taken in this CL to only use strings that required no additional construction, mainly to minimize garbage (retaining references to newly created strings is not as great a concern since only the strings corresponding to the slowest K tasks are retained, for some relatively small values of K). Action descriptions for actually executing actions are eagerly expanded because that work is minimal compared to the work of actually executing an action.
PiperOrigin-RevId: 191251488
-rw-r--r--src/main/java/com/google/devtools/build/lib/actions/Action.java3
-rw-r--r--src/main/java/com/google/devtools/build/lib/actions/ActionExecutionMetadata.java3
-rw-r--r--src/main/java/com/google/devtools/build/lib/actions/ResourceManager.java4
-rw-r--r--src/main/java/com/google/devtools/build/lib/exec/TestStrategy.java2
-rw-r--r--src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java16
-rw-r--r--src/main/java/com/google/devtools/build/lib/profiler/Describable.java29
-rw-r--r--src/main/java/com/google/devtools/build/lib/profiler/Profiler.java126
-rw-r--r--src/main/java/com/google/devtools/build/lib/rules/cpp/CppCompileAction.java13
-rw-r--r--src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java12
-rw-r--r--src/main/java/com/google/devtools/build/lib/syntax/Lexer.java3
-rw-r--r--src/main/java/com/google/devtools/build/lib/vfs/JavaIoFileSystem.java4
-rw-r--r--src/main/java/com/google/devtools/build/lib/vfs/UnixGlob.java43
-rw-r--r--src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java2
-rw-r--r--src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java2
-rw-r--r--src/test/java/com/google/devtools/build/lib/actions/ResourceManagerTest.java5
-rw-r--r--src/test/java/com/google/devtools/build/lib/exec/util/FakeOwner.java5
-rw-r--r--src/test/java/com/google/devtools/build/lib/profiler/AutoProfilerBenchmark.java7
17 files changed, 125 insertions, 154 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/actions/Action.java b/src/main/java/com/google/devtools/build/lib/actions/Action.java
index 0111313e4f..72c881c4ef 100644
--- a/src/main/java/com/google/devtools/build/lib/actions/Action.java
+++ b/src/main/java/com/google/devtools/build/lib/actions/Action.java
@@ -16,7 +16,6 @@ package com.google.devtools.build.lib.actions;
import com.google.devtools.build.lib.actions.extra.ExtraActionInfo;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ConditionallyThreadCompatible;
-import com.google.devtools.build.lib.profiler.Describable;
import com.google.devtools.build.lib.vfs.FileSystem;
import com.google.devtools.build.lib.vfs.Path;
import com.google.devtools.build.skyframe.SkyFunction;
@@ -76,7 +75,7 @@ import javax.annotation.Nullable;
* known set of fields is covered, not that all fields are covered), so carefully check all changes
* to action subclasses.
*/
-public interface Action extends ActionExecutionMetadata, Describable {
+public interface Action extends ActionExecutionMetadata {
/**
* Prepares for executing this action; called by the Builder prior to executing the Action itself.
* This method should prepare the file system, so that the execution of the Action can write the
diff --git a/src/main/java/com/google/devtools/build/lib/actions/ActionExecutionMetadata.java b/src/main/java/com/google/devtools/build/lib/actions/ActionExecutionMetadata.java
index 57ad70d90d..f904bcc10c 100644
--- a/src/main/java/com/google/devtools/build/lib/actions/ActionExecutionMetadata.java
+++ b/src/main/java/com/google/devtools/build/lib/actions/ActionExecutionMetadata.java
@@ -102,6 +102,9 @@ public interface ActionExecutionMetadata extends ActionAnalysisMetadata {
@Nullable
String describeKey();
+ /** Returns a description of this action. */
+ String describe();
+
/**
* Get the {@link RunfilesSupplier} providing runfiles needed by this action.
*/
diff --git a/src/main/java/com/google/devtools/build/lib/actions/ResourceManager.java b/src/main/java/com/google/devtools/build/lib/actions/ResourceManager.java
index bd23215d21..5a6303a16b 100644
--- a/src/main/java/com/google/devtools/build/lib/actions/ResourceManager.java
+++ b/src/main/java/com/google/devtools/build/lib/actions/ResourceManager.java
@@ -203,7 +203,7 @@ public class ResourceManager {
Preconditions.checkState(
!threadHasResources(), "acquireResources with existing resource lock during %s", owner);
- AutoProfiler p = profiled(owner, ProfilerTask.ACTION_LOCK);
+ AutoProfiler p = profiled(owner.describe(), ProfilerTask.ACTION_LOCK);
CountDownLatch latch = null;
try {
latch = acquire(resources);
@@ -300,7 +300,7 @@ public class ResourceManager {
threadHasResources(), "releaseResources without resource lock during %s", owner);
boolean isConflict = false;
- AutoProfiler p = profiled(owner, ProfilerTask.ACTION_RELEASE);
+ AutoProfiler p = profiled(owner.describe(), ProfilerTask.ACTION_RELEASE);
try {
isConflict = release(resources);
} finally {
diff --git a/src/main/java/com/google/devtools/build/lib/exec/TestStrategy.java b/src/main/java/com/google/devtools/build/lib/exec/TestStrategy.java
index 3a64bab76a..b457eba6c4 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/TestStrategy.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/TestStrategy.java
@@ -351,7 +351,7 @@ public abstract class TestStrategy implements TestActionContext {
// local test sharding.
long startTime = Profiler.nanoTimeMaybe();
synchronized (execSettings.getInputManifest()) {
- Profiler.instance().logSimpleTask(startTime, ProfilerTask.WAIT, testAction);
+ Profiler.instance().logSimpleTask(startTime, ProfilerTask.WAIT, testAction.describe());
updateLocalRunfilesDirectory(
testAction,
runfilesDir,
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java b/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java
index 555613da83..a181cce069 100644
--- a/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java
+++ b/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java
@@ -158,13 +158,13 @@ public class AutoProfiler implements AutoCloseable {
}
/**
- * Returns an {@link AutoProfiler} that, when closed, records the elapsed time using
- * {@link Profiler}.
+ * Returns an {@link AutoProfiler} that, when closed, records the elapsed time using {@link
+ * Profiler}.
*
* <p>The returned {@link AutoProfiler} is thread-safe.
*/
- public static AutoProfiler profiled(Object object, ProfilerTask profilerTaskType) {
- return create(new ProfilingElapsedTimeReceiver(object, profilerTaskType));
+ public static AutoProfiler profiled(String description, ProfilerTask profilerTaskType) {
+ return create(new ProfilingElapsedTimeReceiver(description, profilerTaskType));
}
/**
@@ -333,12 +333,12 @@ public class AutoProfiler implements AutoCloseable {
private static class ProfilingElapsedTimeReceiver implements ElapsedTimeReceiver {
private final long startTimeNanos;
- private final Object object;
+ private final String description;
private final ProfilerTask profilerTaskType;
- private ProfilingElapsedTimeReceiver(Object object, ProfilerTask profilerTaskType) {
+ private ProfilingElapsedTimeReceiver(String description, ProfilerTask profilerTaskType) {
this.startTimeNanos = Profiler.nanoTimeMaybe();
- this.object = object;
+ this.description = description;
this.profilerTaskType = profilerTaskType;
}
@@ -347,7 +347,7 @@ public class AutoProfiler implements AutoCloseable {
if (elapsedTimeNanos > 0) {
Profiler.instance()
.logSimpleTaskDuration(
- startTimeNanos, Duration.ofNanos(elapsedTimeNanos), profilerTaskType, object);
+ startTimeNanos, Duration.ofNanos(elapsedTimeNanos), profilerTaskType, description);
}
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Describable.java b/src/main/java/com/google/devtools/build/lib/profiler/Describable.java
deleted file mode 100644
index 71ea6e2d0d..0000000000
--- a/src/main/java/com/google/devtools/build/lib/profiler/Describable.java
+++ /dev/null
@@ -1,29 +0,0 @@
-// Copyright 2014 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.profiler;
-
-/**
- * Allows class to implement profiler-friendly (and user-friendly)
- * textual description of the object that would uniquely identify an object in
- * the profiler data dump.
- */
-public interface Describable {
-
- /**
- * Returns textual description that will uniquely identify an object.
- */
- String describe();
-
-}
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 b58c21d9c2..e9113ce823 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
@@ -145,12 +145,12 @@ public final class Profiler {
/** A task that was very slow. */
public static final class SlowTask implements Comparable<SlowTask> {
final long durationNanos;
- final Object object;
+ final String description;
ProfilerTask type;
private SlowTask(TaskData taskData) {
this.durationNanos = taskData.duration;
- this.object = taskData.object;
+ this.description = taskData.description;
this.type = taskData.type;
}
@@ -171,7 +171,7 @@ public final class Profiler {
}
public String getDescription() {
- return toDescription(object);
+ return description;
}
public ProfilerTask getType() {
@@ -196,10 +196,9 @@ public final class Profiler {
int[] counts; // number of invocations per ProfilerTask type
long[] durations; // time spend in the task per ProfilerTask type
final ProfilerTask type;
- final Object object;
+ final String description;
- TaskData(long startTime, TaskData parent,
- ProfilerTask eventType, Object object) {
+ TaskData(long startTime, TaskData parent, ProfilerTask eventType, String description) {
threadId = Thread.currentThread().getId();
counts = null;
durations = null;
@@ -207,7 +206,7 @@ public final class Profiler {
parentId = (parent == null ? 0 : parent.id);
this.startTime = startTime;
this.type = eventType;
- this.object = Preconditions.checkNotNull(object);
+ this.description = Preconditions.checkNotNull(description);
}
/**
@@ -226,7 +225,7 @@ public final class Profiler {
@Override
public String toString() {
- return "Thread " + threadId + ", task " + id + ", type " + type + ", " + object;
+ return "Thread " + threadId + ", task " + id + ", type " + type + ", " + description;
}
}
@@ -264,12 +263,12 @@ public final class Profiler {
return get().isEmpty();
}
- public void push(ProfilerTask eventType, Object object) {
- get().add(create(clock.nanoTime(), eventType, object));
+ public void push(ProfilerTask eventType, String description) {
+ get().add(create(clock.nanoTime(), eventType, description));
}
- public TaskData create(long startTime, ProfilerTask eventType, Object object) {
- return new TaskData(startTime, peek(), eventType, object);
+ public TaskData create(long startTime, ProfilerTask eventType, String description) {
+ return new TaskData(startTime, peek(), eventType, description);
}
@Override
@@ -285,12 +284,6 @@ public final class Profiler {
}
}
- private static String toDescription(Object object) {
- return (object instanceof Describable)
- ? ((Describable) object).describe()
- : object.toString();
- }
-
/**
* Implements datastore for object description indices. Intended to be used only by the
* Profiler.save() method.
@@ -302,21 +295,24 @@ public final class Profiler {
ObjectDescriber() { }
- int getDescriptionIndex(Object object) {
- Integer index = descMap.get(object);
+ int getDescriptionIndex(String description) {
+ Integer index = descMap.get(description);
return (index != null) ? index : -1;
}
- String getDescription(Object object) {
- String description = toDescription(object);
-
- Integer oldIndex = descMap.put(object, indexCounter++);
+ String memoizeDescription(String description) {
+ Integer oldIndex = descMap.put(description, indexCounter++);
// Do not use Preconditions class below due to the rather expensive
// toString() calls used in the message.
if (oldIndex != null) {
- throw new IllegalStateException(" Object '" + description + "' @ "
- + System.identityHashCode(object) + " already had description index "
- + oldIndex + " while assigning index " + descMap.get(object));
+ throw new IllegalStateException(
+ description
+ + "' @ "
+ + System.identityHashCode(description)
+ + " already had description index "
+ + oldIndex
+ + " while assigning index "
+ + descMap.get(description));
} else if (description.length() > 20000) {
// Note size 64k byte limitation in DataOutputStream#writeUTF().
description = description.substring(0, 20000);
@@ -643,7 +639,7 @@ public final class Profiler {
// To save space (and improve performance), convert all description
// strings to the canonical object and use IdentityHashMap to assign
// unique numbers for each string.
- int descIndex = describer.getDescriptionIndex(data.object);
+ int descIndex = describer.getDescriptionIndex(data.description);
VarInt.putVarInt(descIndex + 1, sink); // Add 1 to avoid encoding negative values.
// Save types using their ordinal() value
@@ -663,7 +659,7 @@ public final class Profiler {
this.out.writeInt(sink.position());
this.out.write(sink.array(), 0, sink.position());
if (describer.isUnassigned(descIndex)) {
- this.out.writeUTF(describer.getDescription(data.object));
+ this.out.writeUTF(describer.memoizeDescription(data.description));
}
}
this.out.flush();
@@ -702,24 +698,24 @@ public final class Profiler {
}
/**
- * Adds task directly to the main queue bypassing task stack. Used for simple
- * tasks that are known to not have any subtasks.
+ * Adds task directly to the main queue bypassing task stack. Used for simple tasks that are known
+ * to not have any subtasks.
*
* @param startTime task start time (obtained through {@link Profiler#nanoTimeMaybe()})
* @param duration task duration
* @param type task type
- * @param object object associated with that task. Can be String object that
- * describes it.
+ * @param description task description. May be stored until end of build.
*/
- private void logTask(long startTime, long duration, ProfilerTask type, Object object) {
- Preconditions.checkNotNull(object);
+ private void logTask(long startTime, long duration, ProfilerTask type, String description) {
+ Preconditions.checkNotNull(description);
Preconditions.checkState(startTime > 0, "startTime was %s", startTime);
if (duration < 0) {
// See note in Clock#nanoTime, which is used by Profiler#nanoTimeMaybe.
duration = 0;
}
- tasksHistograms[type.ordinal()].addStat((int) TimeUnit.NANOSECONDS.toMillis(duration), object);
+ tasksHistograms[type.ordinal()].addStat(
+ (int) TimeUnit.NANOSECONDS.toMillis(duration), description);
// Store instance fields as local variables so they are not nulled out from under us by #clear.
TaskStack localStack = taskStack;
Queue<TaskData> localQueue = taskQueue;
@@ -734,7 +730,7 @@ public final class Profiler {
parent.aggregateChild(type, duration);
}
if (wasTaskSlowEnoughToRecord(type, duration)) {
- TaskData data = localStack.create(startTime, type, object);
+ TaskData data = localStack.create(startTime, type, description);
data.duration = duration;
if (out != null) {
localQueue.add(data);
@@ -749,19 +745,17 @@ public final class Profiler {
}
/**
- * Used externally to submit simple task (one that does not have any subtasks).
- * Depending on the minDuration attribute of the task type, task may be
- * just aggregated into the parent task and not stored directly.
+ * Used externally to submit simple task (one that does not have any subtasks). Depending on the
+ * minDuration attribute of the task type, task may be just aggregated into the parent task and
+ * not stored directly.
*
- * @param startTime task start time (obtained through {@link
- * Profiler#nanoTimeMaybe()})
+ * @param startTime task start time (obtained through {@link Profiler#nanoTimeMaybe()})
* @param type task type
- * @param object object associated with that task. Can be String object that
- * describes it.
+ * @param description task description. May be stored until the end of the build.
*/
- public void logSimpleTask(long startTime, ProfilerTask type, Object object) {
+ public void logSimpleTask(long startTime, ProfilerTask type, String description) {
if (isActive() && isProfiling(type)) {
- logTask(startTime, clock.nanoTime() - startTime, type, object);
+ logTask(startTime, clock.nanoTime() - startTime, type, description);
}
}
@@ -775,12 +769,12 @@ public final class Profiler {
* @param startTimeNanos task start time
* @param stopTimeNanos task stop time
* @param type task type
- * @param object object associated with that task. Can be String object that describes it.
+ * @param description task description. May be stored until the end of the build.
*/
public void logSimpleTask(
- long startTimeNanos, long stopTimeNanos, ProfilerTask type, Object object) {
+ long startTimeNanos, long stopTimeNanos, ProfilerTask type, String description) {
if (isActive() && isProfiling(type)) {
- logTask(startTimeNanos, stopTimeNanos - startTimeNanos, type, object);
+ logTask(startTimeNanos, stopTimeNanos - startTimeNanos, type, description);
}
}
@@ -792,46 +786,42 @@ public final class Profiler {
* @param startTimeNanos task start time (obtained through {@link Profiler#nanoTimeMaybe()})
* @param duration the duration of the task
* @param type task type
- * @param object object associated with that task. Can be String object that describes it.
+ * @param description task description. May be stored until the end of the build.
*/
public void logSimpleTaskDuration(
- long startTimeNanos, Duration duration, ProfilerTask type, Object object) {
+ long startTimeNanos, Duration duration, ProfilerTask type, String description) {
if (isActive() && isProfiling(type)) {
- logTask(startTimeNanos, duration.toNanos(), type, object);
+ logTask(startTimeNanos, duration.toNanos(), type, description);
}
}
- /**
- * Used to log "events" - tasks with zero duration.
- */
- public void logEvent(ProfilerTask type, Object object) {
+ /** Used to log "events" - tasks with zero duration. */
+ public void logEvent(ProfilerTask type, String description) {
if (isActive() && isProfiling(type)) {
- logTask(clock.nanoTime(), 0, type, object);
+ logTask(clock.nanoTime(), 0, type, description);
}
}
/**
- * Records the beginning of the task specified by the parameters. This method
- * should always be followed by completeTask() invocation to mark the end of
- * task execution (usually ensured by try {} finally {} block). Failure to do
- * so will result in task stack corruption.
+ * Records the beginning of the task specified by the parameters. This method should always be
+ * followed by completeTask() invocation to mark the end of task execution (usually ensured by try
+ * {} finally {} block). Failure to do so will result in task stack corruption.
*
- * Use of this method allows to support nested task monitoring. For tasks that
- * are known to not have any subtasks, logSimpleTask() should be used instead.
+ * <p>Use of this method allows to support nested task monitoring. For tasks that are known to not
+ * have any subtasks, logSimpleTask() should be used instead.
*
* @param type predefined task type - see ProfilerTask for available types.
- * @param object object associated with that task. Can be String object that
- * describes it.
+ * @param description task description. May be stored until the end of the build.
*/
- public void startTask(ProfilerTask type, Object object) {
+ public void startTask(ProfilerTask type, String description) {
// ProfilerInfo.allTasksById is supposed to be an id -> Task map, but it is in fact a List,
// which means that we cannot drop tasks to which we had already assigned ids. Therefore,
// non-leaf tasks must not have a minimum duration. However, we don't quite consistently
// enforce this, and Blaze only works because we happen not to add child tasks to those parent
// tasks that have a minimum duration.
- Preconditions.checkNotNull(object);
+ Preconditions.checkNotNull(description);
if (isActive() && isProfiling(type)) {
- taskStack.push(type, object);
+ taskStack.push(type, description);
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/rules/cpp/CppCompileAction.java b/src/main/java/com/google/devtools/build/lib/rules/cpp/CppCompileAction.java
index 1e7b65b4b6..913088648f 100644
--- a/src/main/java/com/google/devtools/build/lib/rules/cpp/CppCompileAction.java
+++ b/src/main/java/com/google/devtools/build/lib/rules/cpp/CppCompileAction.java
@@ -1003,17 +1003,12 @@ public class CppCompileAction extends AbstractAction
}
}
- /**
- * Recalculates this action's live input collection, including sources, middlemen.
- *
- * @throws ActionExecutionException iff any errors happen during update.
- */
- @VisibleForTesting // productionVisibility = Visibility.PRIVATE
+ /** Recalculates this action's live input collection, including sources, middlemen. */
+ @VisibleForTesting // productionVisibility = Visibility.PRIVATE
@ThreadCompatible
- public final void updateActionInputs(NestedSet<Artifact> discoveredInputs)
- throws ActionExecutionException {
+ public final void updateActionInputs(NestedSet<Artifact> discoveredInputs) {
NestedSetBuilder<Artifact> inputs = NestedSetBuilder.stableOrder();
- Profiler.instance().startTask(ProfilerTask.ACTION_UPDATE, this);
+ Profiler.instance().startTask(ProfilerTask.ACTION_UPDATE, describe());
try {
inputs.addTransitive(mandatoryInputs);
if (optionalSourceFile != 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 ff12e07091..49017083e6 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
@@ -496,7 +496,7 @@ public final class SkyframeActionExecutor implements ActionExecutionContextFacto
long actionStartTime,
Iterable<Artifact> resolvedCacheArtifacts,
Map<String, String> clientEnv) {
- profiler.startTask(ProfilerTask.ACTION_CHECK, action);
+ startProfileAction(ProfilerTask.ACTION_CHECK, action);
Token token =
actionCacheChecker.getTokenIfNeedToExecute(
action, resolvedCacheArtifacts, clientEnv, explain ? reporter : null, metadataHandler);
@@ -641,6 +641,10 @@ public final class SkyframeActionExecutor implements ActionExecutionContextFacto
this.actionInputPrefetcher = actionInputPrefetcher;
}
+ private void startProfileAction(ProfilerTask task, Action action) {
+ profiler.startTask(task, action.describe());
+ }
+
private class ActionRunner implements Callable<ActionExecutionValue> {
private final ExtendedEventHandler eventHandler;
private final Action action;
@@ -666,7 +670,7 @@ public final class SkyframeActionExecutor implements ActionExecutionContextFacto
@Override
public ActionExecutionValue call() throws ActionExecutionException, InterruptedException {
- profiler.startTask(ProfilerTask.ACTION, action);
+ startProfileAction(ProfilerTask.ACTION, action);
try {
if (actionCacheChecker.isActionExecutionProhibited(action)) {
// We can't execute an action (e.g. because --check_???_up_to_date option was used). Fail
@@ -883,7 +887,7 @@ public final class SkyframeActionExecutor implements ActionExecutionContextFacto
Action action,
ActionExecutionContext actionExecutionContext)
throws ActionExecutionException, InterruptedException {
- profiler.startTask(ProfilerTask.ACTION_EXECUTE, action);
+ startProfileAction(ProfilerTask.ACTION_EXECUTE, action);
// ActionExecutionExceptions that occur as the thread is interrupted are
// assumed to be a result of that, so we throw InterruptedException
// instead.
@@ -922,7 +926,7 @@ public final class SkyframeActionExecutor implements ActionExecutionContextFacto
Preconditions.checkState(action.inputsDiscovered(),
"Action %s successfully executed, but inputs still not known", action);
- profiler.startTask(ProfilerTask.ACTION_COMPLETE, action);
+ startProfileAction(ProfilerTask.ACTION_COMPLETE, action);
try {
if (!checkOutputs(action, metadataHandler)) {
reportError("not all outputs were created or valid", null, action,
diff --git a/src/main/java/com/google/devtools/build/lib/syntax/Lexer.java b/src/main/java/com/google/devtools/build/lib/syntax/Lexer.java
index 5f80c418cf..91fbc1bf00 100644
--- a/src/main/java/com/google/devtools/build/lib/syntax/Lexer.java
+++ b/src/main/java/com/google/devtools/build/lib/syntax/Lexer.java
@@ -109,7 +109,8 @@ public final class Lexer {
indentStack.push(0);
long startTime = Profiler.nanoTimeMaybe();
tokenize();
- Profiler.instance().logSimpleTask(startTime, ProfilerTask.SKYLARK_LEXER, getFilename());
+ Profiler.instance()
+ .logSimpleTask(startTime, ProfilerTask.SKYLARK_LEXER, getFilename().getPathString());
}
public Lexer(ParserInputSource input, EventHandler eventHandler) {
diff --git a/src/main/java/com/google/devtools/build/lib/vfs/JavaIoFileSystem.java b/src/main/java/com/google/devtools/build/lib/vfs/JavaIoFileSystem.java
index f5b0220e32..ecda1b4ba1 100644
--- a/src/main/java/com/google/devtools/build/lib/vfs/JavaIoFileSystem.java
+++ b/src/main/java/com/google/devtools/build/lib/vfs/JavaIoFileSystem.java
@@ -303,7 +303,7 @@ public class JavaIoFileSystem extends AbstractFileSystemWithCustomStat {
} catch (java.nio.file.NoSuchFileException e) {
throw new FileNotFoundException(path + ERR_NO_SUCH_FILE_OR_DIR);
} finally {
- profiler.logSimpleTask(startTime, ProfilerTask.VFS_READLINK, nioPath);
+ profiler.logSimpleTask(startTime, ProfilerTask.VFS_READLINK, path.getPathString());
}
}
@@ -337,7 +337,7 @@ public class JavaIoFileSystem extends AbstractFileSystemWithCustomStat {
try {
return stat(path, followSymlinks).getSize();
} finally {
- profiler.logSimpleTask(startTime, ProfilerTask.VFS_STAT, path);
+ profiler.logSimpleTask(startTime, ProfilerTask.VFS_STAT, path.getPathString());
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/vfs/UnixGlob.java b/src/main/java/com/google/devtools/build/lib/vfs/UnixGlob.java
index 74f1fa89a2..c70270c6a2 100644
--- a/src/main/java/com/google/devtools/build/lib/vfs/UnixGlob.java
+++ b/src/main/java/com/google/devtools/build/lib/vfs/UnixGlob.java
@@ -602,32 +602,33 @@ public final class UnixGlob {
/** Should only be called by link {@GlobTaskContext}. */
private void queueGlob(final Path base, final boolean baseIsDir, final int idx,
final GlobTaskContext context) {
- enqueue(new Runnable() {
- @Override
- public void run() {
- Profiler.instance().startTask(ProfilerTask.VFS_GLOB, this);
- try {
- reallyGlob(base, baseIsDir, idx, context);
- } catch (IOException e) {
- ioException.set(e);
- } catch (RuntimeException e) {
- runtimeException.set(e);
- } catch (Error e) {
- error.set(e);
- } finally {
- Profiler.instance().completeTask(ProfilerTask.VFS_GLOB);
- }
- }
+ enqueue(
+ new Runnable() {
+ @Override
+ public void run() {
+ Profiler.instance().startTask(ProfilerTask.VFS_GLOB, base.getPathString());
+ try {
+ reallyGlob(base, baseIsDir, idx, context);
+ } catch (IOException e) {
+ ioException.set(e);
+ } catch (RuntimeException e) {
+ runtimeException.set(e);
+ } catch (Error e) {
+ error.set(e);
+ } finally {
+ Profiler.instance().completeTask(ProfilerTask.VFS_GLOB);
+ }
+ }
- @Override
- public String toString() {
- return String.format(
+ @Override
+ public String toString() {
+ return String.format(
"%s glob(include=[%s], exclude_directories=%s)",
base.getPathString(),
"\"" + Joiner.on("\", \"").join(context.patternParts) + "\"",
context.excludeDirectories);
- }
- });
+ }
+ });
}
protected void enqueue(final Runnable r) {
diff --git a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
index b13c685b78..9526c855d9 100644
--- a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
+++ b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
@@ -206,7 +206,7 @@ public abstract class AbstractExceptionalParallelEvaluator<E extends Exception>
}
}
- Profiler.instance().startTask(ProfilerTask.SKYFRAME_EVAL, skyKeySet);
+ Profiler.instance().startTask(ProfilerTask.SKYFRAME_EVAL, "Parallel Evaluator evaluation");
try {
return doMutatingEvaluation(skyKeySet);
} finally {
diff --git a/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java b/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
index 92ad4d674e..1391d00e1b 100644
--- a/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
+++ b/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
@@ -354,7 +354,7 @@ public abstract class AbstractParallelEvaluator {
startTime,
Duration.ofNanos(elapsedTimeNanos),
ProfilerTask.SKYFUNCTION,
- skyKey);
+ skyKey.functionName().getName());
}
}
} catch (final SkyFunctionException builderException) {
diff --git a/src/test/java/com/google/devtools/build/lib/actions/ResourceManagerTest.java b/src/test/java/com/google/devtools/build/lib/actions/ResourceManagerTest.java
index fe4776826f..4d25bde4cb 100644
--- a/src/test/java/com/google/devtools/build/lib/actions/ResourceManagerTest.java
+++ b/src/test/java/com/google/devtools/build/lib/actions/ResourceManagerTest.java
@@ -561,6 +561,11 @@ public class ResourceManagerTest {
}
@Override
+ public String describe() {
+ return "ResourceOwnerStubAction";
+ }
+
+ @Override
public ImmutableSet<Artifact> getMandatoryOutputs() {
return ImmutableSet.of();
}
diff --git a/src/test/java/com/google/devtools/build/lib/exec/util/FakeOwner.java b/src/test/java/com/google/devtools/build/lib/exec/util/FakeOwner.java
index bc54d6735b..aaf7197819 100644
--- a/src/test/java/com/google/devtools/build/lib/exec/util/FakeOwner.java
+++ b/src/test/java/com/google/devtools/build/lib/exec/util/FakeOwner.java
@@ -135,6 +135,11 @@ public final class FakeOwner implements ActionExecutionMetadata {
}
@Override
+ public String describe() {
+ return getProgressMessage();
+ }
+
+ @Override
public Iterable<Artifact> getInputFilesForExtraAction(
ActionExecutionContext actionExecutionContext) {
return ImmutableList.of();
diff --git a/src/test/java/com/google/devtools/build/lib/profiler/AutoProfilerBenchmark.java b/src/test/java/com/google/devtools/build/lib/profiler/AutoProfilerBenchmark.java
index 671c96e711..ae2f93f7e5 100644
--- a/src/test/java/com/google/devtools/build/lib/profiler/AutoProfilerBenchmark.java
+++ b/src/test/java/com/google/devtools/build/lib/profiler/AutoProfilerBenchmark.java
@@ -23,8 +23,6 @@ import com.google.devtools.build.lib.vfs.inmemoryfs.InMemoryFileSystem;
* Microbenchmarks for the overhead of {@link AutoProfiler} over using {@link Profiler} manually.
*/
public class AutoProfilerBenchmark {
-
- private final Object obj = new Object();
private final ProfilerTask profilerTaskType = ProfilerTask.TEST;
@BeforeExperiment
@@ -42,8 +40,7 @@ public class AutoProfilerBenchmark {
@Benchmark
void profiledWithAutoProfiler(int reps) {
for (int i = 0; i < reps; i++) {
- try (AutoProfiler p = AutoProfiler.profiled(obj, profilerTaskType)) {
- }
+ try (AutoProfiler p = AutoProfiler.profiled("profiling", profilerTaskType)) {}
}
}
@@ -51,7 +48,7 @@ public class AutoProfilerBenchmark {
void profiledManually(int reps) {
for (int i = 0; i < reps; i++) {
long startTime = Profiler.nanoTimeMaybe();
- Profiler.instance().logSimpleTask(startTime, profilerTaskType, obj);
+ Profiler.instance().logSimpleTask(startTime, profilerTaskType, "description");
}
}
}