Skip to content

Commit e382cb2

Browse files
coeuvrecopybara-github
coeuvre
authored and
copybara-github
committed
Collect system network usages in profiler.
Guarded by flag `--experimental_collect_system_network_usage`, the profiler can now collect system network usages. The data is collected by system calls through JNI which is only implemented on macOS in this change. PiperOrigin-RevId: 473744411 Change-Id: I845fececcbb92e883723e5eba90b58340f7e8dfb
1 parent f828488 commit e382cb2

17 files changed

Lines changed: 571 additions & 2 deletions

File tree

‎src/main/java/com/google/devtools/build/lib/profiler/BUILD‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ java_library(
2626
"TimeSeries.java",
2727
],
2828
deps = [
29+
":system_network_stats",
2930
"//src/main/java/com/google/devtools/build/lib/bugreport",
3031
"//src/main/java/com/google/devtools/build/lib/clock",
3132
"//src/main/java/com/google/devtools/build/lib/collect:extrema",
@@ -36,12 +37,22 @@ java_library(
3637
"//src/main/java/com/google/devtools/common/options",
3738
"//third_party:auto_value",
3839
"//third_party:error_prone_annotations",
40+
"//third_party:flogger",
3941
"//third_party:gson",
4042
"//third_party:guava",
4143
"//third_party:jsr305",
4244
],
4345
)
4446

47+
java_library(
48+
name = "system_network_stats",
49+
srcs = ["SystemNetworkStats.java"],
50+
deps = [
51+
"//src/main/java/com/google/devtools/build/lib/jni",
52+
"//third_party:auto_value",
53+
],
54+
)
55+
4556
java_library(
4657
name = "google-auto-profiler-utils",
4758
srcs = ["GoogleAutoProfilerUtils.java"],

‎src/main/java/com/google/devtools/build/lib/profiler/CollectLocalResourceUsage.java‎

Lines changed: 158 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,11 @@
1717

1818
import com.google.common.base.Preconditions;
1919
import com.google.common.base.Stopwatch;
20+
import com.google.common.collect.ImmutableSet;
21+
import com.google.common.flogger.GoogleLogger;
2022
import com.google.devtools.build.lib.bugreport.BugReporter;
23+
import com.google.devtools.build.lib.profiler.SystemNetworkStats.NetIfAddr;
24+
import com.google.devtools.build.lib.profiler.SystemNetworkStats.NetIoCounter;
2125
import com.google.devtools.build.lib.unix.ProcMeminfoParser;
2226
import com.google.devtools.build.lib.util.OS;
2327
import com.google.devtools.build.lib.worker.WorkerMetric;
@@ -28,18 +32,24 @@
2832
import java.lang.management.ManagementFactory;
2933
import java.lang.management.MemoryMXBean;
3034
import java.time.Duration;
35+
import java.util.List;
36+
import java.util.Map;
3137
import java.util.Objects;
38+
import java.util.Set;
3239
import java.util.concurrent.TimeUnit;
3340

3441
/** Thread to collect local resource usage data and log into JSON profile. */
3542
public class CollectLocalResourceUsage extends Thread {
43+
private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
44+
3645
// TODO(twerth): Make these configurable.
3746
private static final Duration BUCKET_DURATION = Duration.ofSeconds(1);
3847
private static final Duration LOCAL_RESOURCES_COLLECT_SLEEP_INTERVAL = Duration.ofMillis(200);
3948

4049
private final BugReporter bugReporter;
4150
private final boolean collectWorkerDataInProfiler;
4251
private final boolean collectLoadAverage;
52+
private final boolean collectSystemNetworkUsage;
4353

4454
private volatile boolean stopLocalUsageCollection;
4555
private volatile boolean profilingStarted;
@@ -62,6 +72,12 @@ public class CollectLocalResourceUsage extends Thread {
6272
@GuardedBy("this")
6373
private TimeSeries systemLoadAverage;
6474

75+
@GuardedBy("this")
76+
private TimeSeries systemNetworkUpUsage;
77+
78+
@GuardedBy("this")
79+
private TimeSeries systemNetworkDownUsage;
80+
6581
private Stopwatch stopwatch;
6682

6783
private final WorkerMetricsCollector workerMetricsCollector;
@@ -70,15 +86,23 @@ public class CollectLocalResourceUsage extends Thread {
7086
BugReporter bugReporter,
7187
WorkerMetricsCollector workerMetricsCollector,
7288
boolean collectWorkerDataInProfiler,
73-
boolean collectLoadAverage) {
89+
boolean collectLoadAverage,
90+
boolean collectSystemNetworkUsage) {
7491
this.bugReporter = checkNotNull(bugReporter);
7592
this.collectWorkerDataInProfiler = collectWorkerDataInProfiler;
7693
this.workerMetricsCollector = workerMetricsCollector;
7794
this.collectLoadAverage = collectLoadAverage;
95+
this.collectSystemNetworkUsage = collectSystemNetworkUsage;
7896
}
7997

8098
@Override
8199
public void run() {
100+
ImmutableSet<String> localLoopbackInterfaces;
101+
if (collectSystemNetworkUsage) {
102+
localLoopbackInterfaces = getLocalLoopbackInterfaces();
103+
} else {
104+
localLoopbackInterfaces = ImmutableSet.of();
105+
}
82106
int numProcessors = Runtime.getRuntime().availableProcessors();
83107
stopwatch = Stopwatch.createStarted();
84108
synchronized (this) {
@@ -104,12 +128,21 @@ public void run() {
104128
new TimeSeries(
105129
/* startTimeMillis= */ stopwatch.elapsed().toMillis(), BUCKET_DURATION.toMillis());
106130
}
131+
if (collectSystemNetworkUsage) {
132+
systemNetworkUpUsage =
133+
new TimeSeries(
134+
/* startTimeMillis= */ stopwatch.elapsed().toMillis(), BUCKET_DURATION.toMillis());
135+
systemNetworkDownUsage =
136+
new TimeSeries(
137+
/* startTimeMillis= */ stopwatch.elapsed().toMillis(), BUCKET_DURATION.toMillis());
138+
}
107139
}
108140
OperatingSystemMXBean osBean =
109141
(OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
110142
MemoryMXBean memoryBean = ManagementFactory.getMemoryMXBean();
111143
Duration previousElapsed = stopwatch.elapsed();
112144
long previousCpuTimeNanos = osBean.getProcessCpuTime();
145+
Map<String, NetIoCounter> previousNetworkIoCounters = null;
113146
profilingStarted = true;
114147
while (!stopLocalUsageCollection) {
115148
try {
@@ -171,6 +204,19 @@ public void run() {
171204

172205
double deltaNanos = nextElapsed.minus(previousElapsed).toNanos();
173206
double cpuLevel = (nextCpuTimeNanos - previousCpuTimeNanos) / deltaNanos;
207+
208+
Map<String, NetIoCounter> nextNetworkIoCounters = null;
209+
if (collectSystemNetworkUsage) {
210+
try {
211+
nextNetworkIoCounters = SystemNetworkStats.getNetIoCounters();
212+
} catch (IOException e) {
213+
logger.atWarning().withCause(e).log("Failed to get Net IO counters");
214+
}
215+
if (previousNetworkIoCounters == null) {
216+
previousNetworkIoCounters = nextNetworkIoCounters;
217+
}
218+
}
219+
174220
synchronized (this) {
175221
if (localCpuUsage != null) {
176222
localCpuUsage.addRange(previousElapsed.toMillis(), nextElapsed.toMillis(), cpuLevel);
@@ -195,9 +241,24 @@ public void run() {
195241
systemLoadAverage.addRange(
196242
previousElapsed.toMillis(), nextElapsed.toMillis(), loadAverage);
197243
}
244+
if (collectSystemNetworkUsage
245+
&& previousNetworkIoCounters != null
246+
&& nextNetworkIoCounters != null) {
247+
AggregatedNetIoCounter aggregated =
248+
aggregateNetIoCounter(
249+
previousNetworkIoCounters,
250+
nextNetworkIoCounters,
251+
deltaNanos,
252+
localLoopbackInterfaces);
253+
systemNetworkUpUsage.addRange(
254+
previousElapsed.toMillis(), nextElapsed.toMillis(), aggregated.upMbps);
255+
systemNetworkDownUsage.addRange(
256+
previousElapsed.toMillis(), nextElapsed.toMillis(), aggregated.downMbps);
257+
}
198258
}
199259
previousElapsed = nextElapsed;
200260
previousCpuTimeNanos = nextCpuTimeNanos;
261+
previousNetworkIoCounters = nextNetworkIoCounters;
201262
}
202263
}
203264

@@ -243,6 +304,23 @@ synchronized void logCollectedData() {
243304
profiler, systemLoadAverage, ProfilerTask.SYSTEM_LOAD_AVERAGE, startTimeNanos, len);
244305
}
245306
systemLoadAverage = null;
307+
308+
if (collectSystemNetworkUsage) {
309+
logCollectedData(
310+
profiler,
311+
systemNetworkUpUsage,
312+
ProfilerTask.SYSTEM_NETWORK_UP_USAGE,
313+
startTimeNanos,
314+
len);
315+
logCollectedData(
316+
profiler,
317+
systemNetworkDownUsage,
318+
ProfilerTask.SYSTEM_NETWORK_DOWN_USAGE,
319+
startTimeNanos,
320+
len);
321+
}
322+
systemNetworkUpUsage = null;
323+
systemNetworkDownUsage = null;
246324
}
247325

248326
private static void logCollectedData(
@@ -253,4 +331,83 @@ private static void logCollectedData(
253331
profiler.logEventAtTime(eventTimeNanos, type, String.valueOf(localResourceValues[i]));
254332
}
255333
}
334+
335+
private boolean isLocalLoopback(List<NetIfAddr> addresses) {
336+
for (NetIfAddr addr : addresses) {
337+
switch (addr.family()) {
338+
case AF_INET:
339+
if (addr.ipAddr().equals("127.0.0.1")) {
340+
return true;
341+
}
342+
break;
343+
case AF_INET6:
344+
if (addr.ipAddr().equals("::1")) {
345+
return true;
346+
}
347+
break;
348+
case UNKNOWN:
349+
}
350+
}
351+
return false;
352+
}
353+
354+
private ImmutableSet<String> getLocalLoopbackInterfaces() {
355+
ImmutableSet.Builder<String> result = ImmutableSet.builder();
356+
try {
357+
for (Map.Entry<String, List<NetIfAddr>> entry :
358+
SystemNetworkStats.getNetIfAddrs().entrySet()) {
359+
if (isLocalLoopback(entry.getValue())) {
360+
result.add(entry.getKey());
361+
}
362+
}
363+
} catch (IOException e) {
364+
logger.atWarning().withCause(e).log("Failed to query network interfaces");
365+
}
366+
return result.build();
367+
}
368+
369+
static class AggregatedNetIoCounter {
370+
private final double upMbps;
371+
private final double downMbps;
372+
373+
AggregatedNetIoCounter(double upMbps, double downMbps) {
374+
this.upMbps = upMbps;
375+
this.downMbps = downMbps;
376+
}
377+
}
378+
379+
private AggregatedNetIoCounter aggregateNetIoCounter(
380+
Map<String, NetIoCounter> previousNetIoCounters,
381+
Map<String, NetIoCounter> nextNetIoCounters,
382+
double deltaNanos,
383+
Set<String> excludedInterfaces) {
384+
long deltaBytesSent = 0;
385+
long deltaBytesRecv = 0;
386+
for (Map.Entry<String, NetIoCounter> entry : previousNetIoCounters.entrySet()) {
387+
String name = entry.getKey();
388+
if (excludedInterfaces.contains(name)) {
389+
continue;
390+
}
391+
NetIoCounter previous = entry.getValue();
392+
NetIoCounter next = nextNetIoCounters.get(name);
393+
deltaBytesSent += calcDeltaBytes(previous.bytesSent(), next.bytesSent());
394+
deltaBytesRecv += calcDeltaBytes(previous.bytesRecv(), next.bytesRecv());
395+
}
396+
double upMbps = calcNetworkMbps(deltaBytesSent, deltaNanos);
397+
double downMbps = calcNetworkMbps(deltaBytesRecv, deltaNanos);
398+
return new AggregatedNetIoCounter(upMbps, downMbps);
399+
}
400+
401+
private long calcDeltaBytes(long prevBytes, long nextBytes) {
402+
// The nextBytes could wrap, and if that happens, assume prevBytes is 0 (best effort).
403+
if (nextBytes < prevBytes) {
404+
return nextBytes;
405+
} else {
406+
return nextBytes - prevBytes;
407+
}
408+
}
409+
410+
private double calcNetworkMbps(long deltaBytes, double deltaNanos) {
411+
return deltaBytes / deltaNanos * 8000;
412+
}
256413
}

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

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -392,6 +392,7 @@ public synchronized void start(
392392
boolean collectTaskHistograms,
393393
boolean collectWorkerDataInProfiler,
394394
boolean collectLoadAverage,
395+
boolean collectSystemNetworkUsage,
395396
WorkerMetricsCollector workerMetricsCollector,
396397
BugReporter bugReporter)
397398
throws IOException {
@@ -450,7 +451,11 @@ public synchronized void start(
450451
// Start collecting Bazel and system-wide CPU metric collection.
451452
resourceUsageThread =
452453
new CollectLocalResourceUsage(
453-
bugReporter, workerMetricsCollector, collectWorkerDataInProfiler, collectLoadAverage);
454+
bugReporter,
455+
workerMetricsCollector,
456+
collectWorkerDataInProfiler,
457+
collectLoadAverage,
458+
collectSystemNetworkUsage);
454459
resourceUsageThread.setDaemon(true);
455460
resourceUsageThread.start();
456461
}
@@ -1159,6 +1164,8 @@ public void run() {
11591164
|| data.type == ProfilerTask.ACTION_COUNTS
11601165
|| data.type == ProfilerTask.SYSTEM_CPU_USAGE
11611166
|| data.type == ProfilerTask.SYSTEM_MEMORY_USAGE
1167+
|| data.type == ProfilerTask.SYSTEM_NETWORK_UP_USAGE
1168+
|| data.type == ProfilerTask.SYSTEM_NETWORK_DOWN_USAGE
11621169
|| data.type == ProfilerTask.WORKERS_MEMORY_USAGE
11631170
|| data.type == ProfilerTask.SYSTEM_LOAD_AVERAGE) {
11641171
// Skip counts equal to zero. They will show up as a thin line in the profile.
@@ -1186,6 +1193,10 @@ public void run() {
11861193
case SYSTEM_MEMORY_USAGE:
11871194
writer.name("cname").value("bad");
11881195
break;
1196+
case SYSTEM_NETWORK_UP_USAGE:
1197+
case SYSTEM_NETWORK_DOWN_USAGE:
1198+
writer.name("cname").value("rail_response");
1199+
break;
11891200
case WORKERS_MEMORY_USAGE:
11901201
writer.name("cname").value("rail_animation");
11911202
break;
@@ -1221,6 +1232,12 @@ public void run() {
12211232
case SYSTEM_MEMORY_USAGE:
12221233
writer.name("system memory").value(data.description);
12231234
break;
1235+
case SYSTEM_NETWORK_UP_USAGE:
1236+
writer.name("system network up (Mbps)").value(data.description);
1237+
break;
1238+
case SYSTEM_NETWORK_DOWN_USAGE:
1239+
writer.name("system network down (Mbps)").value(data.description);
1240+
break;
12241241
case WORKERS_MEMORY_USAGE:
12251242
writer.name("workers memory").value(data.description);
12261243
break;

‎src/main/java/com/google/devtools/build/lib/profiler/ProfilerTask.java‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,8 @@ public enum ProfilerTask {
6969
SYSTEM_CPU_USAGE("CPU usage (total)"),
7070
LOCAL_MEMORY_USAGE("Memory usage (Bazel)"),
7171
SYSTEM_MEMORY_USAGE("Memory usage (total)"),
72+
SYSTEM_NETWORK_UP_USAGE("Network Up usage (total)"),
73+
SYSTEM_NETWORK_DOWN_USAGE("Network Down usage (total)"),
7274
WORKERS_MEMORY_USAGE("Workers memory usage"),
7375
SYSTEM_LOAD_AVERAGE("System load average"),
7476
STARLARK_PARSER("Starlark Parser", Threshold.FIFTY_MILLIS),

0 commit comments

Comments
 (0)