Skip to content

Commit 1077721

Browse files
coeuvrecopybara-github
authored andcommitted
Support profiling in an virtual thread.
Instead of using `Thread.currentThread().threadId()` for the `threadId` in the `Profiler`, we maintain a map of `threadId` to `laneId` for virtual threads so a same lane in the UI can be re-used for different virtual threads. This change requires using `Profiler#profileableVirtualThreadFactory()` to create VirtualThread which can use `Profiler`. PiperOrigin-RevId: 622814148 Change-Id: I5a6bad039c95b287456597dceb158b487f61fc86
1 parent d5a86b3 commit 1077721

File tree

6 files changed

+135
-55
lines changed

6 files changed

+135
-55
lines changed

src/main/java/com/google/devtools/build/lib/bazel/BUILD

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,7 @@ java_library(
4444
"//src/main/java/com/google/devtools/build/lib/cmdline",
4545
"//src/main/java/com/google/devtools/build/lib/events",
4646
"//src/main/java/com/google/devtools/build/lib/pkgcache",
47+
"//src/main/java/com/google/devtools/build/lib/profiler",
4748
"//src/main/java/com/google/devtools/build/lib/rules:repository/local_repository_rule",
4849
"//src/main/java/com/google/devtools/build/lib/rules:repository/new_local_repository_function",
4950
"//src/main/java/com/google/devtools/build/lib/rules:repository/new_local_repository_rule",

src/main/java/com/google/devtools/build/lib/bazel/BazelRepositoryModule.java

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -77,6 +77,7 @@
7777
import com.google.devtools.build.lib.cmdline.RepositoryName;
7878
import com.google.devtools.build.lib.events.Event;
7979
import com.google.devtools.build.lib.pkgcache.PackageOptions;
80+
import com.google.devtools.build.lib.profiler.Profiler;
8081
import com.google.devtools.build.lib.rules.repository.LocalRepositoryFunction;
8182
import com.google.devtools.build.lib.rules.repository.LocalRepositoryRule;
8283
import com.google.devtools.build.lib.rules.repository.NewLocalRepositoryFunction;
@@ -121,6 +122,7 @@
121122
import java.util.Optional;
122123
import java.util.concurrent.ExecutorService;
123124
import java.util.concurrent.Executors;
125+
import java.util.concurrent.ThreadFactory;
124126
import java.util.concurrent.atomic.AtomicBoolean;
125127
import java.util.stream.Collectors;
126128
import javax.annotation.Nullable;
@@ -325,8 +327,11 @@ public void beforeCommand(CommandEnvironment env) throws AbruptExitException {
325327
starlarkRepositoryFunction.setWorkerExecutorService(
326328
(ExecutorService)
327329
Executors.class
328-
.getDeclaredMethod("newVirtualThreadPerTaskExecutor")
329-
.invoke(null));
330+
.getDeclaredMethod("newThreadPerTaskExecutor", ThreadFactory.class)
331+
.invoke(
332+
null,
333+
Profiler.instance()
334+
.profileableVirtualThreadFactory("starlark-repository-")));
330335
} catch (ReflectiveOperationException e) {
331336
if (repoOptions.workerForRepoFetching == RepositoryOptions.WorkerForRepoFetching.AUTO) {
332337
starlarkRepositoryFunction.setWorkerExecutorService(null);

src/main/java/com/google/devtools/build/lib/profiler/JsonTraceFileWriter.java

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,9 @@ public void start() {
8585
}
8686

8787
public void enqueue(TraceData data) {
88-
if (!metadataPosted.get()) {
88+
// We assign a virtual lane for virtual thread and the metadata for the virtual lane is posted
89+
// at creation time.
90+
if (!Thread.currentThread().isVirtual() && !metadataPosted.get()) {
8991
metadataPosted.set(Boolean.TRUE);
9092
queue.add(new ThreadMetadata());
9193
}

src/main/java/com/google/devtools/build/lib/profiler/Profiler.java

Lines changed: 115 additions & 51 deletions
Original file line numberDiff line numberDiff line change
@@ -46,12 +46,14 @@
4646
import java.util.PriorityQueue;
4747
import java.util.Set;
4848
import java.util.UUID;
49+
import java.util.concurrent.ThreadFactory;
4950
import java.util.concurrent.TimeUnit;
5051
import java.util.concurrent.atomic.AtomicLong;
5152
import java.util.concurrent.atomic.AtomicReference;
5253
import java.util.function.Supplier;
5354
import java.util.zip.GZIPOutputStream;
5455
import javax.annotation.Nullable;
56+
import javax.annotation.concurrent.GuardedBy;
5557

5658
/**
5759
* Blaze internal profiler. Provides facility to report various Blaze tasks and store them
@@ -274,8 +276,7 @@ private static final class SlowestTaskAggregator {
274276

275277
// @ThreadSafe
276278
void add(TaskData taskData) {
277-
Extrema<SlowTask> extrema =
278-
extremaAggregators[(int) (Thread.currentThread().getId() % SHARDS)];
279+
Extrema<SlowTask> extrema = extremaAggregators[(int) (taskData.threadId % SHARDS)];
279280
synchronized (extrema) {
280281
extrema.aggregate(new SlowTask(taskData));
281282
}
@@ -659,12 +660,7 @@ private void logTask(
659660
*/
660661
public void logSimpleTask(long startTimeNanos, ProfilerTask type, String description) {
661662
if (clock != null) {
662-
logTask(
663-
Thread.currentThread().getId(),
664-
startTimeNanos,
665-
clock.nanoTime() - startTimeNanos,
666-
type,
667-
description);
663+
logTask(getLaneId(), startTimeNanos, clock.nanoTime() - startTimeNanos, type, description);
668664
}
669665
}
670666

@@ -682,12 +678,7 @@ public void logSimpleTask(long startTimeNanos, ProfilerTask type, String descrip
682678
*/
683679
public void logSimpleTask(
684680
long startTimeNanos, long stopTimeNanos, ProfilerTask type, String description) {
685-
logTask(
686-
Thread.currentThread().getId(),
687-
startTimeNanos,
688-
stopTimeNanos - startTimeNanos,
689-
type,
690-
description);
681+
logTask(getLaneId(), startTimeNanos, stopTimeNanos - startTimeNanos, type, description);
691682
}
692683

693684
/**
@@ -702,12 +693,12 @@ public void logSimpleTask(
702693
*/
703694
public void logSimpleTaskDuration(
704695
long startTimeNanos, Duration duration, ProfilerTask type, String description) {
705-
logTask(Thread.currentThread().getId(), startTimeNanos, duration.toNanos(), type, description);
696+
logTask(getLaneId(), startTimeNanos, duration.toNanos(), type, description);
706697
}
707698

708699
/** Used to log "events" happening at a specific time - tasks with zero duration. */
709700
public void logEventAtTime(long atTimeNanos, ProfilerTask type, String description) {
710-
logTask(Thread.currentThread().getId(), atTimeNanos, 0, type, description);
701+
logTask(getLaneId(), atTimeNanos, 0, type, description);
711702
}
712703

713704
/** Used to log "events" - tasks with zero duration. */
@@ -741,7 +732,7 @@ private SilentCloseable reallyProfile(long laneId, ProfilerTask type, String des
741732
* @param description task description. May be stored until the end of the build.
742733
*/
743734
public SilentCloseable profile(ProfilerTask type, String description) {
744-
return profile(Thread.currentThread().getId(), type, description);
735+
return profile(getLaneId(), type, description);
745736
}
746737

747738
private SilentCloseable profile(long laneId, ProfilerTask type, String description) {
@@ -753,7 +744,7 @@ private SilentCloseable profile(long laneId, ProfilerTask type, String descripti
753744
* profiling.
754745
*/
755746
public SilentCloseable profile(ProfilerTask type, Supplier<String> description) {
756-
return profile(Thread.currentThread().getId(), type, description);
747+
return profile(getLaneId(), type, description);
757748
}
758749

759750
private SilentCloseable profile(long laneId, ProfilerTask type, Supplier<String> description) {
@@ -799,7 +790,7 @@ public SilentCloseable profileAction(
799790
final long startTimeNanos = clock.nanoTime();
800791
return () ->
801792
completeAction(
802-
Thread.currentThread().getId(),
793+
getLaneId(),
803794
startTimeNanos,
804795
type,
805796
description,
@@ -824,7 +815,7 @@ private boolean countAction(ProfilerTask type, TaskData taskData) {
824815
}
825816

826817
public void completeTask(long startTimeNanos, ProfilerTask type, String description) {
827-
completeTask(Thread.currentThread().getId(), startTimeNanos, type, description);
818+
completeTask(getLaneId(), startTimeNanos, type, description);
828819
}
829820

830821
/** Records the end of the task. */
@@ -969,72 +960,145 @@ public interface FutureSupplier<T> {
969960
}
970961

971962
public <T> ListenableFuture<T> profileAsync(
972-
ProfilerTaskType type, String description, FutureSupplier<T> futureSupplier) {
963+
String prefix, String description, FutureSupplier<T> futureSupplier) {
973964
if (!(isActive() && isProfiling(ProfilerTask.INFO))) {
974965
return futureSupplier.get(new ScopedProfiler(/* active= */ false, 0));
975966
}
976967

977-
long laneId = laneIdGenerator.acquire(type);
968+
var lane = multiLaneGenerator.acquire(prefix);
978969
final long startTimeNanos = clock.nanoTime();
979-
var scopedProfiler = new ScopedProfiler(/* active= */ true, laneId);
970+
var scopedProfiler = new ScopedProfiler(/* active= */ true, lane.id());
980971
var future = futureSupplier.get(scopedProfiler);
981972
future.addListener(
982973
() -> {
983974
long endTimeNanos = clock.nanoTime();
984975
long duration = endTimeNanos - startTimeNanos;
985976
recordTask(
986-
new TaskData(laneId, startTimeNanos, duration, ProfilerTask.INFO, description));
987-
laneIdGenerator.release(type, laneId);
977+
new TaskData(lane.id(), startTimeNanos, duration, ProfilerTask.INFO, description));
978+
multiLaneGenerator.release(prefix, lane);
988979
},
989980
MoreExecutors.directExecutor());
990981
return future;
991982
}
992983

993-
private static final long LANE_ID_BASE = 1_000_000;
994-
private final AtomicLong nextLaneId = new AtomicLong(LANE_ID_BASE);
995-
private final TaskTypeLaneIdGenerator laneIdGenerator = new TaskTypeLaneIdGenerator();
984+
private final ThreadLocal<String> virtualThreadPrefix = ThreadLocal.withInitial(() -> null);
985+
private final ThreadLocal<Lane> borrowedLane = ThreadLocal.withInitial(() -> null);
996986

997-
private class TaskTypeLaneIdGenerator {
998-
private final Map<ProfilerTaskType, LaneIdGenerator> typeToLaneIdGenerator =
999-
Maps.newConcurrentMap();
987+
private void registerVirtualThread(String prefix) {
988+
var thread = Thread.currentThread();
989+
var threadId = thread.threadId();
990+
virtualThreadPrefix.set(prefix);
991+
thread.setName(prefix + threadId);
992+
}
993+
994+
private void deregisterVirtualThread() {
995+
var prefix = checkNotNull(virtualThreadPrefix.get());
996+
virtualThreadPrefix.remove();
997+
var lane = borrowedLane.get();
998+
if (lane != null) {
999+
borrowedLane.remove();
1000+
multiLaneGenerator.release(prefix, lane);
1001+
}
1002+
}
1003+
1004+
private final AtomicLong nextLaneId = new AtomicLong(1_000_000);
1005+
private final MultiLaneGenerator multiLaneGenerator = new MultiLaneGenerator();
1006+
1007+
private class MultiLaneGenerator {
1008+
private final Map<String, LaneGenerator> laneGenerators = Maps.newConcurrentMap();
10001009

1001-
public long acquire(ProfilerTaskType type) {
1002-
var laneIdGenerator =
1003-
typeToLaneIdGenerator.computeIfAbsent(type, unused -> new LaneIdGenerator(type));
1004-
return laneIdGenerator.acquire();
1010+
private Lane acquire(String prefix) {
1011+
checkState(isActive());
1012+
var laneGenerator =
1013+
laneGenerators.computeIfAbsent(prefix, unused -> new LaneGenerator(prefix));
1014+
return laneGenerator.acquire();
10051015
}
10061016

1007-
public void release(ProfilerTaskType type, long laneId) {
1008-
var laneIdGenerator = checkNotNull(typeToLaneIdGenerator.get(type));
1009-
laneIdGenerator.release(laneId);
1017+
private void release(String prefix, Lane lane) {
1018+
checkState(isActive());
1019+
var laneGenerator = checkNotNull(laneGenerators.get(prefix));
1020+
laneGenerator.release(lane);
10101021
}
10111022
}
10121023

1013-
private class LaneIdGenerator {
1014-
private final ProfilerTaskType type;
1015-
private final PriorityQueue<Long> availableLaneIds = new PriorityQueue<>();
1024+
private record Lane(long id) implements Comparable<Lane> {
1025+
@Override
1026+
public int compareTo(Lane o) {
1027+
return Long.compare(id, o.id);
1028+
}
1029+
}
1030+
1031+
private class LaneGenerator {
1032+
private final String prefix;
1033+
1034+
@GuardedBy("this")
1035+
private final PriorityQueue<Lane> availableLanes = new PriorityQueue<>();
10161036

1037+
@GuardedBy("this")
10171038
private int count = 0;
10181039

1019-
private LaneIdGenerator(ProfilerTaskType type) {
1020-
this.type = type;
1040+
private LaneGenerator(String prefix) {
1041+
this.prefix = prefix;
10211042
}
10221043

1023-
public synchronized long acquire() {
1024-
if (!availableLaneIds.isEmpty()) {
1025-
return availableLaneIds.poll();
1044+
public Lane acquire() {
1045+
long newLaneId;
1046+
String newLaneName;
1047+
synchronized (this) {
1048+
if (!availableLanes.isEmpty()) {
1049+
return availableLanes.poll();
1050+
}
1051+
1052+
newLaneId = nextLaneId.getAndIncrement();
1053+
int newLaneIndex = count++;
1054+
newLaneName = prefix + newLaneIndex + " (Virtual)";
10261055
}
1027-
var newLaneId = Profiler.this.nextLaneId.getAndIncrement();
1028-
var threadMetadata = new ThreadMetadata(type.getName(count++), newLaneId, LANE_ID_BASE);
1056+
1057+
var threadMetadata = new ThreadMetadata(newLaneName, newLaneId);
10291058
var writer = Profiler.this.writerRef.get();
10301059
if (writer != null) {
10311060
writer.enqueue(threadMetadata);
10321061
}
1033-
return newLaneId;
1062+
return new Lane(newLaneId);
10341063
}
10351064

1036-
public synchronized void release(long laneId) {
1037-
availableLaneIds.add(laneId);
1065+
public synchronized void release(Lane lane) {
1066+
availableLanes.add(lane);
10381067
}
10391068
}
1069+
1070+
private long getLaneId() {
1071+
var currentThread = Thread.currentThread();
1072+
var threadId = currentThread.threadId();
1073+
if (!currentThread.isVirtual()) {
1074+
return threadId;
1075+
}
1076+
1077+
var lane = borrowedLane.get();
1078+
if (lane == null) {
1079+
var prefix = virtualThreadPrefix.get();
1080+
checkNotNull(
1081+
prefix,
1082+
"Current virtual thread is not registered. Did you use"
1083+
+ " Profiler#profileableVirtualThreadFactor to create a VirtualThread?");
1084+
lane = multiLaneGenerator.acquire(prefix);
1085+
borrowedLane.set(lane);
1086+
}
1087+
return lane.id();
1088+
}
1089+
1090+
public ThreadFactory profileableVirtualThreadFactory(String prefix) {
1091+
return r ->
1092+
Thread.ofVirtual()
1093+
.unstarted(
1094+
() -> {
1095+
var profiler = Profiler.instance();
1096+
profiler.registerVirtualThread(prefix);
1097+
try {
1098+
r.run();
1099+
} finally {
1100+
profiler.deregisterVirtualThread();
1101+
}
1102+
});
1103+
}
10401104
}

src/main/java/com/google/devtools/build/lib/profiler/ThreadMetadata.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,12 @@ class ThreadMetadata implements TraceData {
2424
private final long threadId;
2525
private final long sortIndex;
2626

27+
public ThreadMetadata(String readableName, long threadId) {
28+
this.readableName = readableName;
29+
this.threadId = threadId;
30+
this.sortIndex = getSortIndex(readableName);
31+
}
32+
2733
public ThreadMetadata(String readableName, long threadId, long sortIndex) {
2834
this.readableName = readableName;
2935
this.threadId = threadId;

src/main/java/com/google/devtools/build/lib/runtime/QuiescingExecutorsImpl.java

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525
import com.google.devtools.build.lib.concurrent.QuiescingExecutor;
2626
import com.google.devtools.build.lib.concurrent.QuiescingExecutors;
2727
import com.google.devtools.build.lib.pkgcache.PackageOptions;
28+
import com.google.devtools.build.lib.profiler.Profiler;
2829
import com.google.devtools.build.skyframe.ParallelEvaluatorErrorClassifier;
2930
import com.google.devtools.common.options.OptionsProvider;
3031
import java.util.concurrent.Executors;
@@ -145,7 +146,8 @@ public QuiescingExecutor getMergedAnalysisAndExecutionExecutor() {
145146
/* parallelism= */ cpuHeavySkyKeysThreadPoolSize, SKYFRAME_EVALUATOR_CPU_HEAVY),
146147
useAsyncExecution
147148
? Executors.newThreadPerTaskExecutor(
148-
Thread.ofVirtual().name(SKYFRAME_EVALUATOR_EXECUTION + "-%s", 0).factory())
149+
Profiler.instance()
150+
.profileableVirtualThreadFactory(SKYFRAME_EVALUATOR_EXECUTION + "-"))
149151
: AbstractQueueVisitor.createExecutorService(
150152
/* parallelism= */ executionParallelism, SKYFRAME_EVALUATOR_EXECUTION),
151153
ExceptionHandlingMode.FAIL_FAST,

0 commit comments

Comments
 (0)