From d233c896fd6eff93901f7dd8641936a76b544ccb Mon Sep 17 00:00:00 2001 From: Googler Date: Thu, 1 Sep 2022 08:32:48 -0700 Subject: [PATCH] Add `lastCallTime` to the WorkerMetrics. Every new worker acquiring updates `lastCallTime`. PiperOrigin-RevId: 471539520 Change-Id: If56782ca027a2f0e2f120733aef00d260fcdf304 --- .../proto/build_event_stream.proto | 2 + .../build/lib/metrics/MetricsCollector.java | 1 + .../build/lib/runtime/BlazeRuntime.java | 2 + .../google/devtools/build/lib/worker/BUILD | 2 + .../build/lib/worker/WorkerMetric.java | 11 +- .../lib/worker/WorkerMetricsCollector.java | 127 +++++++++++------- .../build/lib/worker/WorkerModule.java | 3 +- .../build/lib/worker/WorkerSpawnRunner.java | 5 +- .../google/devtools/build/lib/metrics/BUILD | 2 + .../lib/metrics/MetricsCollectorTest.java | 7 + .../build/lib/profiler/ProfilerTest.java | 4 +- .../worker/WorkerLifecycleManagerTest.java | 31 +++-- .../worker/WorkerMetricsCollectorTest.java | 95 +++++++++---- .../lib/worker/WorkerSpawnRunnerTest.java | 22 ++- 14 files changed, 212 insertions(+), 102 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto b/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto index a9b73cfee4a027..f3359552640691 100644 --- a/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto +++ b/src/main/java/com/google/devtools/build/lib/buildeventstream/proto/build_event_stream.proto @@ -1056,6 +1056,8 @@ message BuildMetrics { int64 collect_time_in_ms = 1; // RSS size of worker process. int32 worker_memory_in_kb = 2; + // Epoch unix time of last action started on specific worker. + int64 last_action_start_time_in_ms = 3; } // Combined workers statistics. diff --git a/src/main/java/com/google/devtools/build/lib/metrics/MetricsCollector.java b/src/main/java/com/google/devtools/build/lib/metrics/MetricsCollector.java index 48bb9b47e83c25..e206f7bb154523 100644 --- a/src/main/java/com/google/devtools/build/lib/metrics/MetricsCollector.java +++ b/src/main/java/com/google/devtools/build/lib/metrics/MetricsCollector.java @@ -91,6 +91,7 @@ private MetricsCollector( this.numAnalyses = numAnalyses; this.numBuilds = numBuilds; env.getEventBus().register(this); + WorkerMetricsCollector.instance().setClock(env.getClock()); } static void installInEnv( 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 ee93b33ec0d44f..ae8a9b81c5401d 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 @@ -384,6 +384,8 @@ ProfilerStartedEvent initProfiler( + " will be omitted in merged actions.")); } Profiler profiler = Profiler.instance(); + WorkerMetricsCollector workerMetricsCollector = WorkerMetricsCollector.instance(); + workerMetricsCollector.setClock(clock); profiler.start( profiledTasks, out, diff --git a/src/main/java/com/google/devtools/build/lib/worker/BUILD b/src/main/java/com/google/devtools/build/lib/worker/BUILD index 1b102251f93085..0f50fbf6107e8d 100644 --- a/src/main/java/com/google/devtools/build/lib/worker/BUILD +++ b/src/main/java/com/google/devtools/build/lib/worker/BUILD @@ -82,6 +82,7 @@ java_library( "//src/main/java/com/google/devtools/build/lib/actions:file_metadata", "//src/main/java/com/google/devtools/build/lib/actions:localhost_capacity", "//src/main/java/com/google/devtools/build/lib/actions:resource_manager", + "//src/main/java/com/google/devtools/build/lib/clock", "//src/main/java/com/google/devtools/build/lib/events", "//src/main/java/com/google/devtools/build/lib/exec:bin_tools", "//src/main/java/com/google/devtools/build/lib/exec:runfiles_tree_updater", @@ -166,6 +167,7 @@ java_library( ], deps = [ "//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:build_event_stream_java_proto", + "//src/main/java/com/google/devtools/build/lib/clock", "//src/main/java/com/google/devtools/build/lib/util:os", "//third_party:auto_value", "//third_party:flogger", diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerMetric.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerMetric.java index 6ce6a387f2c0f0..c6d40333739e00 100644 --- a/src/main/java/com/google/devtools/build/lib/worker/WorkerMetric.java +++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerMetric.java @@ -43,10 +43,12 @@ public static WorkerMetric create( public abstract static class WorkerStat { public abstract int getUsedMemoryInKB(); - public abstract Instant getTimestamp(); + public abstract Instant getLastCallTime(); - public static WorkerStat create(int usedMemoryInKB, Instant timestamp) { - return new AutoValue_WorkerMetric_WorkerStat(usedMemoryInKB, timestamp); + public abstract Instant getCollectTime(); + + public static WorkerStat create(int usedMemoryInKB, Instant lastCallTime, Instant collectTime) { + return new AutoValue_WorkerMetric_WorkerStat(usedMemoryInKB, lastCallTime, collectTime); } } @@ -86,8 +88,9 @@ public WorkerMetrics toProto() { if (workerStat != null) { WorkerStats stats = WorkerMetrics.WorkerStats.newBuilder() - .setCollectTimeInMs(workerStat.getTimestamp().toEpochMilli()) + .setCollectTimeInMs(workerStat.getCollectTime().toEpochMilli()) .setWorkerMemoryInKb(workerStat.getUsedMemoryInKB()) + .setLastActionStartTimeInMs(workerStat.getLastCallTime().toEpochMilli()) .build(); builder.addWorkerStats(stats); } diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerMetricsCollector.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerMetricsCollector.java index 2fcf8cb285bf21..2655602bbdaf32 100644 --- a/src/main/java/com/google/devtools/build/lib/worker/WorkerMetricsCollector.java +++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerMetricsCollector.java @@ -15,14 +15,19 @@ package com.google.devtools.build.lib.worker; import static com.google.common.collect.ImmutableList.toImmutableList; +import static com.google.common.collect.ImmutableSet.toImmutableSet; import static java.nio.charset.StandardCharsets.UTF_8; import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Joiner; import com.google.common.base.Splitter; import com.google.common.collect.ImmutableList; +import com.google.common.collect.ImmutableMap; +import com.google.common.collect.ImmutableSet; import com.google.common.flogger.GoogleLogger; +import com.google.devtools.build.lib.clock.Clock; import com.google.devtools.build.lib.util.OS; +import com.google.devtools.build.lib.worker.WorkerMetric.WorkerStat; import java.io.BufferedReader; import java.io.IOException; import java.io.InputStreamReader; @@ -43,10 +48,17 @@ public class WorkerMetricsCollector { /** The metrics collector (a static singleton instance). Inactive by default. */ private static final WorkerMetricsCollector instance = new WorkerMetricsCollector(); - /** Mapping of worker ids to their metrics. */ + private Clock clock; + + /** + * Mapping of worker ids to their metrics. Contains worker ids, which memory usage could be + * measured. + */ private final Map workerIdToWorkerProperties = new ConcurrentHashMap<>(); + private final Map workerLastCallTime = new ConcurrentHashMap<>(); + private MetricsWithTime lastMetrics = new MetricsWithTime(ImmutableList.of(), Instant.EPOCH); private WorkerMetricsCollector() {} @@ -55,17 +67,23 @@ public static WorkerMetricsCollector instance() { return instance; } - // Collects process stats for each worker - @VisibleForTesting - public Map collectStats(OS os, List processIds) { + public void setClock(Clock clock) { + this.clock = clock; + } + + /** + * Collects memory usage of all ancestors of processes by pid. If a pid does not allow collecting + * memory usage, it is silently ignored. + */ + MemoryCollectionResult collectMemoryUsageByPid(OS os, ImmutableSet processIds) { // TODO(b/181317827): Support Windows. if (os != OS.LINUX && os != OS.DARWIN) { - return new HashMap<>(); + return new MemoryCollectionResult( + ImmutableMap.of(), Instant.ofEpochMilli(clock.currentTimeMillis())); } - Map pidsToWorkerPid = getSubprocesses(processIds); - Instant now = Instant.now(); - Map psMemory = collectDataFromPs(pidsToWorkerPid.keySet()); + ImmutableMap pidsToWorkerPid = getSubprocesses(processIds); + ImmutableMap psMemory = collectDataFromPs(pidsToWorkerPid.keySet()); Map sumMemory = new HashMap<>(); psMemory.forEach( @@ -78,20 +96,16 @@ public Map collectStats(OS os, List process sumMemory.put(parent, parentMemory + memory); }); - Map pidResults = new HashMap<>(); - sumMemory.forEach( - (parent, memory) -> pidResults.put(parent, WorkerMetric.WorkerStat.create(memory, now))); - - return pidResults; + return new MemoryCollectionResult( + ImmutableMap.copyOf(sumMemory), Instant.ofEpochMilli(clock.currentTimeMillis())); } /** * For each parent process collects pids of all descendants. Stores them into the map, where key * is the descendant pid and the value is parent pid. */ - @VisibleForTesting - public Map getSubprocesses(List parents) { - Map subprocessesToProcess = new HashMap<>(); + ImmutableMap getSubprocesses(ImmutableSet parents) { + ImmutableMap.Builder subprocessesToProcess = ImmutableMap.builder(); for (Long pid : parents) { Optional processHandle = ProcessHandle.of(pid); @@ -105,22 +119,21 @@ public Map getSubprocesses(List parents) { } } - return subprocessesToProcess; + return subprocessesToProcess.buildKeepingLast(); } // Collects memory usage for every process - private Map collectDataFromPs(Collection pids) { + private ImmutableMap collectDataFromPs(Collection pids) { BufferedReader psOutput; try { psOutput = - new BufferedReader( - new InputStreamReader(this.buildPsProcess(pids).getInputStream(), UTF_8)); + new BufferedReader(new InputStreamReader(buildPsProcess(pids).getInputStream(), UTF_8)); } catch (IOException e) { logger.atWarning().withCause(e).log("Error while executing command for pids: %s", pids); - return new HashMap<>(); + return ImmutableMap.of(); } - HashMap processMemory = new HashMap<>(); + ImmutableMap.Builder processMemory = ImmutableMap.builder(); try { // The output of the above ps command looks similar to this: @@ -151,7 +164,7 @@ private Map collectDataFromPs(Collection pids) { logger.atWarning().withCause(e).log("Error while parsing psOutput: %s", psOutput); } - return processMemory; + return processMemory.buildOrThrow(); } @VisibleForTesting @@ -167,8 +180,8 @@ public Process buildPsProcess(Collection processIds) throws IOException { * returns previously collected metrics; */ public ImmutableList collectMetrics(Duration interval) { - Instant now = Instant.now(); - if (Duration.between(this.lastMetrics.time, now).compareTo(interval) < 0) { + Instant now = Instant.ofEpochMilli(clock.currentTimeMillis()); + if (Duration.between(lastMetrics.time, now).compareTo(interval) < 0) { return lastMetrics.metrics; } @@ -177,37 +190,44 @@ public ImmutableList collectMetrics(Duration interval) { // TODO(wilwell): add exception if we couldn't collect the metrics. public ImmutableList collectMetrics() { - Map workerStats = - collectStats( + MemoryCollectionResult memoryCollectionResult = + collectMemoryUsageByPid( OS.getCurrent(), - this.workerIdToWorkerProperties.values().stream() + workerIdToWorkerProperties.values().stream() .map(WorkerMetric.WorkerProperties::getProcessId) - .collect(toImmutableList())); + .collect(toImmutableSet())); + + ImmutableMap pidToMemoryInKb = memoryCollectionResult.pidToMemoryInKb; + Instant collectionTime = memoryCollectionResult.collectionTime; ImmutableList.Builder workerMetrics = new ImmutableList.Builder<>(); List nonMeasurableWorkerIds = new ArrayList<>(); - for (WorkerMetric.WorkerProperties workerProperties : - this.workerIdToWorkerProperties.values()) { + for (WorkerMetric.WorkerProperties workerProperties : workerIdToWorkerProperties.values()) { Long pid = workerProperties.getProcessId(); Integer workerId = workerProperties.getWorkerId(); - if (workerStats.containsKey(pid)) { - workerMetrics.add( - WorkerMetric.create(workerProperties, workerStats.get(pid), /* isMeasurable= */ true)); - } else { - workerMetrics.add( - WorkerMetric.create( - workerProperties, /* workerStat= */ null, /* isMeasurable= */ false)); + + WorkerStat workerStats = + WorkerStat.create( + pidToMemoryInKb.getOrDefault(pid, 0), + workerLastCallTime.get(workerId), + collectionTime); + + workerMetrics.add( + WorkerMetric.create( + workerProperties, workerStats, /* isMeasurable= */ pidToMemoryInKb.containsKey(pid))); + + if (!pidToMemoryInKb.containsKey(pid)) { nonMeasurableWorkerIds.add(workerId); } } workerIdToWorkerProperties.keySet().removeAll(nonMeasurableWorkerIds); - return updateLastCollectMetrics(workerMetrics.build(), Instant.now()).metrics; + return updateLastCollectMetrics(workerMetrics.build(), collectionTime).metrics; } public void clear() { - this.workerIdToWorkerProperties.clear(); + workerIdToWorkerProperties.clear(); } @VisibleForTesting @@ -215,21 +235,25 @@ public Map getWorkerIdToWorkerProperties return workerIdToWorkerProperties; } + @VisibleForTesting + public Map getWorkerLastCallTime() { + return workerLastCallTime; + } + /** * Initializes workerIdToWorkerProperties for workers. If worker metrics already exists for this - * worker, does nothing. + * worker, only updates workerLastCallTime. */ public void registerWorker(WorkerMetric.WorkerProperties properties) { - if (workerIdToWorkerProperties.containsKey(properties.getWorkerId())) { - return; - } + int workerId = properties.getWorkerId(); - workerIdToWorkerProperties.put(properties.getWorkerId(), properties); + workerIdToWorkerProperties.putIfAbsent(workerId, properties); + workerLastCallTime.put(workerId, Instant.ofEpochMilli(clock.currentTimeMillis())); } private synchronized MetricsWithTime updateLastCollectMetrics( ImmutableList metrics, Instant time) { - this.lastMetrics = new MetricsWithTime(metrics, time); + lastMetrics = new MetricsWithTime(metrics, time); return lastMetrics; } @@ -243,5 +267,16 @@ public MetricsWithTime(ImmutableList metrics, Instant time) { } } + static class MemoryCollectionResult { + public final ImmutableMap pidToMemoryInKb; + public final Instant collectionTime; + + public MemoryCollectionResult( + ImmutableMap pidToMemoryInKb, Instant collectionTime) { + this.pidToMemoryInKb = pidToMemoryInKb; + this.collectionTime = collectionTime; + } + } + // TODO(b/238416583) Add deregister function } diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerModule.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerModule.java index 9a02b16584360e..42f55d5bd82e6c 100644 --- a/src/main/java/com/google/devtools/build/lib/worker/WorkerModule.java +++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerModule.java @@ -167,7 +167,8 @@ public void registerSpawnStrategies( RunfilesTreeUpdater.INSTANCE, env.getOptions().getOptions(WorkerOptions.class), WorkerMetricsCollector.instance(), - env.getXattrProvider()); + env.getXattrProvider(), + env.getClock()); ExecutionOptions executionOptions = checkNotNull(env.getOptions().getOptions(ExecutionOptions.class)); registryBuilder.registerStrategy( diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerSpawnRunner.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerSpawnRunner.java index c0d7eb366dc37a..b9d7aa1dd874c8 100644 --- a/src/main/java/com/google/devtools/build/lib/worker/WorkerSpawnRunner.java +++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerSpawnRunner.java @@ -39,6 +39,7 @@ import com.google.devtools.build.lib.actions.Spawns; import com.google.devtools.build.lib.actions.UserExecException; import com.google.devtools.build.lib.actions.cache.VirtualActionInput; +import com.google.devtools.build.lib.clock.Clock; import com.google.devtools.build.lib.events.ExtendedEventHandler; import com.google.devtools.build.lib.exec.BinTools; import com.google.devtools.build.lib.exec.RunfilesTreeUpdater; @@ -111,7 +112,8 @@ public WorkerSpawnRunner( RunfilesTreeUpdater runfilesTreeUpdater, WorkerOptions workerOptions, WorkerMetricsCollector workerMetricsCollector, - XattrProvider xattrProvider) { + XattrProvider xattrProvider, + Clock clock) { this.helpers = helpers; this.execRoot = execRoot; this.workers = checkNotNull(workers); @@ -124,6 +126,7 @@ public WorkerSpawnRunner( this.workerOptions = workerOptions; this.resourceManager.setWorkerPool(workers); this.metricsCollector = workerMetricsCollector; + this.metricsCollector.setClock(clock); } @Override diff --git a/src/test/java/com/google/devtools/build/lib/metrics/BUILD b/src/test/java/com/google/devtools/build/lib/metrics/BUILD index 4a10a7ac8ef558..7aba0044ac5b2e 100644 --- a/src/test/java/com/google/devtools/build/lib/metrics/BUILD +++ b/src/test/java/com/google/devtools/build/lib/metrics/BUILD @@ -36,11 +36,13 @@ java_test( "//src/main/java/com/google/devtools/build/lib/actions", "//src/main/java/com/google/devtools/build/lib/analysis:view_creation_failed_exception", "//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:build_event_stream_java_proto", + "//src/main/java/com/google/devtools/build/lib/clock", "//src/main/java/com/google/devtools/build/lib/metrics:event", "//src/main/java/com/google/devtools/build/lib/metrics:memory-use-recorder", "//src/main/java/com/google/devtools/build/lib/metrics:metrics_module", "//src/main/java/com/google/devtools/build/lib/profiler", "//src/main/java/com/google/devtools/build/lib/util:os", + "//src/main/java/com/google/devtools/build/lib/worker:worker_metric", "//src/test/java/com/google/devtools/build/lib/buildtool/util", "//third_party:guava", "//third_party:junit4", diff --git a/src/test/java/com/google/devtools/build/lib/metrics/MetricsCollectorTest.java b/src/test/java/com/google/devtools/build/lib/metrics/MetricsCollectorTest.java index cc2bbabf68e52c..aad30995cbacd5 100644 --- a/src/test/java/com/google/devtools/build/lib/metrics/MetricsCollectorTest.java +++ b/src/test/java/com/google/devtools/build/lib/metrics/MetricsCollectorTest.java @@ -26,11 +26,13 @@ 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.buildtool.util.BuildIntegrationTestCase; +import com.google.devtools.build.lib.clock.JavaClock; import com.google.devtools.build.lib.profiler.MemoryProfiler; import com.google.devtools.build.lib.runtime.BlazeModule; import com.google.devtools.build.lib.runtime.BlazeRuntime; import com.google.devtools.build.lib.runtime.CommandEnvironment; import com.google.devtools.build.lib.util.OS; +import com.google.devtools.build.lib.worker.WorkerMetricsCollector; import java.util.List; import org.junit.After; import org.junit.Assume; @@ -79,6 +81,11 @@ public void writeTrivialFooTarget() throws Exception { ")"); } + @Before + public void setUpWorkerMetricsCollecto() { + WorkerMetricsCollector.instance().setClock(new JavaClock()); + } + @After public void resetProfilers() throws Exception { MemoryProfiler.instance().stop(); 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 ebd59a8c62f758..748e07a4a5ee70 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 @@ -280,7 +280,7 @@ public void testProfilerWorkerMetrics() throws Exception { /* mnemonic= */ "dummy1", /* isMultiplex= */ true, /* isSandboxed= */ true), - WorkerMetric.WorkerStat.create(1024, Instant.now()), + WorkerMetric.WorkerStat.create(1024, Instant.now(), Instant.now()), /* isMeasurable= */ true), WorkerMetric.create( WorkerMetric.WorkerProperties.create( @@ -289,7 +289,7 @@ public void testProfilerWorkerMetrics() throws Exception { /* mnemonic= */ "dummy2", /* isMultiplex= */ false, /* isSandboxed= */ false), - WorkerMetric.WorkerStat.create(2048, Instant.now()), + WorkerMetric.WorkerStat.create(2048, Instant.now(), Instant.now()), /* isMeasurable= */ true), WorkerMetric.create( WorkerMetric.WorkerProperties.create( diff --git a/src/test/java/com/google/devtools/build/lib/worker/WorkerLifecycleManagerTest.java b/src/test/java/com/google/devtools/build/lib/worker/WorkerLifecycleManagerTest.java index fe054507f71284..66a30787c5daed 100644 --- a/src/test/java/com/google/devtools/build/lib/worker/WorkerLifecycleManagerTest.java +++ b/src/test/java/com/google/devtools/build/lib/worker/WorkerLifecycleManagerTest.java @@ -84,7 +84,7 @@ public void testEvictWorkers_doNothing_lowMemoryUsage() throws Exception { ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(1024, Instant.now()), + createWorkerStat(1024), true)); WorkerOptions options = new WorkerOptions(); options.totalWorkerMemoryLimitMb = 1024 * 100; @@ -112,7 +112,7 @@ public void testEvictWorkers_doNothing_zeroThreshold() throws Exception { ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(1024, Instant.now()), + createWorkerStat(1024), true)); WorkerOptions options = new WorkerOptions(); options.totalWorkerMemoryLimitMb = 0; @@ -163,7 +163,7 @@ public void testGetEvictionCandidates_selectOnlyWorker() throws Exception { ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(2 * 1000, Instant.now()), + createWorkerStat(2000), true)); WorkerOptions options = new WorkerOptions(); options.totalWorkerMemoryLimitMb = 1; @@ -195,15 +195,15 @@ public void testGetEvictionCandidates_evictLargestWorkers() throws Exception { ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(2 * 1000, Instant.now()), + createWorkerStat(2000), true), WorkerMetric.create( createWorkerProperties(w2.getWorkerId(), 2L, "dummy"), - WorkerMetric.WorkerStat.create(1 * 1000, Instant.now()), + createWorkerStat(1000), true), WorkerMetric.create( createWorkerProperties(w3.getWorkerId(), 3L, "dummy"), - WorkerMetric.WorkerStat.create(4 * 1000, Instant.now()), + createWorkerStat(4000), true)); WorkerOptions options = new WorkerOptions(); @@ -236,15 +236,15 @@ public void testGetEvictionCandidates_evictOnlyIdleWorkers() throws Exception { ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(2 * 1000, Instant.now()), + createWorkerStat(2000), true), WorkerMetric.create( createWorkerProperties(w2.getWorkerId(), 2L, "dummy"), - WorkerMetric.WorkerStat.create(1 * 1000, Instant.now()), + createWorkerStat(1000), true), WorkerMetric.create( createWorkerProperties(w3.getWorkerId(), 3L, "dummy"), - WorkerMetric.WorkerStat.create(4 * 1000, Instant.now()), + createWorkerStat(4000), true)); WorkerOptions options = new WorkerOptions(); @@ -283,19 +283,19 @@ public void testGetEvictionCandidates_evictDifferentWorkerKeys() throws Exceptio ImmutableList.of( WorkerMetric.create( createWorkerProperties(w1.getWorkerId(), 1L, "dummy"), - WorkerMetric.WorkerStat.create(1 * 1000, Instant.now()), + createWorkerStat(1000), true), WorkerMetric.create( createWorkerProperties(w2.getWorkerId(), 2L, "dummy"), - WorkerMetric.WorkerStat.create(4 * 1000, Instant.now()), + createWorkerStat(4000), true), WorkerMetric.create( createWorkerProperties(w3.getWorkerId(), 3L, "smart"), - WorkerMetric.WorkerStat.create(3 * 1000, Instant.now()), + createWorkerStat(3000), true), WorkerMetric.create( createWorkerProperties(w4.getWorkerId(), 4L, "smart"), - WorkerMetric.WorkerStat.create(1 * 1000, Instant.now()), + createWorkerStat(1000), true)); WorkerOptions options = new WorkerOptions(); @@ -323,6 +323,11 @@ private static WorkerMetric.WorkerProperties createWorkerProperties( workerId, processId, mnemonic, /* isMultiplex= */ false, /* isSandboxed= */ false); } + private static WorkerMetric.WorkerStat createWorkerStat(int memoryUsage) { + return WorkerMetric.WorkerStat.create( + memoryUsage, /*lastCallTimestamp */ Instant.now(), /* timestamp*/ Instant.now()); + } + private static ImmutableList> emptyEntryList() { return ImmutableList.of(); } diff --git a/src/test/java/com/google/devtools/build/lib/worker/WorkerMetricsCollectorTest.java b/src/test/java/com/google/devtools/build/lib/worker/WorkerMetricsCollectorTest.java index 462c6a019ec7e8..9c0fb5f39275ec 100644 --- a/src/test/java/com/google/devtools/build/lib/worker/WorkerMetricsCollectorTest.java +++ b/src/test/java/com/google/devtools/build/lib/worker/WorkerMetricsCollectorTest.java @@ -23,13 +23,12 @@ import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableMap; +import com.google.common.collect.ImmutableSet; +import com.google.devtools.build.lib.clock.Clock; import com.google.devtools.build.lib.util.OS; import java.io.ByteArrayInputStream; import java.io.InputStream; import java.time.Instant; -import java.util.Arrays; -import java.util.List; -import java.util.Map; import org.junit.Before; import org.junit.Rule; import org.junit.Test; @@ -46,11 +45,13 @@ public class WorkerMetricsCollectorTest { @Rule public final MockitoRule mockito = MockitoJUnit.rule(); private final WorkerMetricsCollector spyCollector = spy(WorkerMetricsCollector.instance()); - @Captor ArgumentCaptor> pidsCaptor; + @Captor ArgumentCaptor> pidsCaptor; + ManualClock clock = new ManualClock(); @Before public void setUp() { - WorkerMetricsCollector.instance().clear(); + spyCollector.clear(); + spyCollector.setClock(clock); } @Test @@ -60,7 +61,7 @@ public void testCollectStats_ignoreSpaces() throws Exception { ImmutableMap.of( 1L, 1L, 2L, 2L); - List pids = Arrays.asList(1L, 2L); + ImmutableSet pids = ImmutableSet.of(1L, 2L); InputStream psStream = new ByteArrayInputStream(psOutput.getBytes(UTF_8)); Process process = mock(Process.class); @@ -68,11 +69,11 @@ public void testCollectStats_ignoreSpaces() throws Exception { when(spyCollector.buildPsProcess(subprocessesMap.keySet())).thenReturn(process); when(process.getInputStream()).thenReturn(psStream); - Map pidResults = spyCollector.collectStats(OS.LINUX, pids); + ImmutableMap memoryUsageByPid = + spyCollector.collectMemoryUsageByPid(OS.LINUX, pids).pidToMemoryInKb; - assertThat(pidResults).hasSize(2); - assertThat(pidResults.get(1L).getUsedMemoryInKB()).isEqualTo(3216); - assertThat(pidResults.get(2L).getUsedMemoryInKB()).isEqualTo(4096); + ImmutableMap expectedMemoryUsageByPid = ImmutableMap.of(1L, 3216, 2L, 4096); + assertThat(memoryUsageByPid).isEqualTo(expectedMemoryUsageByPid); } @Test @@ -86,7 +87,7 @@ public void testCollectStats_mutipleSubprocesses() throws Exception { 4L, 2L, 5L, 5L, 6L, 1L); - List pids = Arrays.asList(1L, 2L, 5L); + ImmutableSet pids = ImmutableSet.of(1L, 2L, 5L); InputStream psStream = new ByteArrayInputStream(psOutput.getBytes(UTF_8)); Process process = mock(Process.class); @@ -94,12 +95,12 @@ public void testCollectStats_mutipleSubprocesses() throws Exception { when(spyCollector.buildPsProcess(subprocessesMap.keySet())).thenReturn(process); when(process.getInputStream()).thenReturn(psStream); - Map pidResults = spyCollector.collectStats(OS.LINUX, pids); + ImmutableMap memoryUsageByPid = + spyCollector.collectMemoryUsageByPid(OS.LINUX, pids).pidToMemoryInKb; - assertThat(pidResults).hasSize(3); - assertThat(pidResults.get(1L).getUsedMemoryInKB()).isEqualTo(3216 + 1234); - assertThat(pidResults.get(2L).getUsedMemoryInKB()).isEqualTo(4232 + 1001); - assertThat(pidResults.get(5L).getUsedMemoryInKB()).isEqualTo(40000); + ImmutableMap expectedMemoryUsageByPid = + ImmutableMap.of(1L, 3216 + 1234, 2L, 4232 + 1001, 5L, 40000); + assertThat(memoryUsageByPid).isEqualTo(expectedMemoryUsageByPid); } @Test @@ -144,13 +145,21 @@ public void testRegisterWorker_insertSame() throws Exception { /*mnemonic= */ "Javac", /*isMultiplex= */ true, /*isSandboxed= */ false); - ImmutableMap map = ImmutableMap.of(1, props1); + Instant registrationTime1 = Instant.ofEpochSecond(1000); + Instant registrationTime2 = registrationTime1.plusSeconds(10); + ImmutableMap propertiesMap = ImmutableMap.of(1, props1); + ImmutableMap lastCallMap1 = ImmutableMap.of(1, registrationTime1); + ImmutableMap lastCallMap2 = ImmutableMap.of(1, registrationTime2); + clock.setTime(registrationTime1.toEpochMilli()); spyCollector.registerWorker(props1); - assertThat(spyCollector.getWorkerIdToWorkerProperties()).hasSize(1); + assertThat(spyCollector.getWorkerIdToWorkerProperties()).isEqualTo(propertiesMap); + assertThat(spyCollector.getWorkerLastCallTime()).isEqualTo(lastCallMap1); + + clock.setTime(registrationTime2.toEpochMilli()); spyCollector.registerWorker(props2); - assertThat(spyCollector.getWorkerIdToWorkerProperties()).hasSize(1); - assertThat(spyCollector.getWorkerIdToWorkerProperties()).isEqualTo(map); + assertThat(spyCollector.getWorkerIdToWorkerProperties()).isEqualTo(propertiesMap); + assertThat(spyCollector.getWorkerLastCallTime()).isEqualTo(lastCallMap2); } @Test @@ -176,24 +185,34 @@ public void testcollectMetrics() throws Exception { /*mnemonic= */ "Proto", /*isMultiplex= */ true, /*isSandboxed= */ true); - WorkerMetric.WorkerStat stat1 = WorkerMetric.WorkerStat.create(1234, Instant.now()); - WorkerMetric.WorkerStat stat2 = WorkerMetric.WorkerStat.create(2345, Instant.now()); + Instant registrationTime = Instant.ofEpochSecond(1000); + Instant collectionTime = registrationTime.plusSeconds(10); + WorkerMetric.WorkerStat stat1 = + WorkerMetric.WorkerStat.create(1234, registrationTime, collectionTime); + WorkerMetric.WorkerStat stat2 = + WorkerMetric.WorkerStat.create(2345, registrationTime, collectionTime); + WorkerMetric.WorkerStat stat3 = + WorkerMetric.WorkerStat.create(0, registrationTime, collectionTime); WorkerMetric workerMetric1 = WorkerMetric.create(props1, stat1, true); WorkerMetric workerMetric2 = WorkerMetric.create(props2, stat2, true); - WorkerMetric workerMetric3 = WorkerMetric.create(props3, null, false); - ImmutableList expectedPids = ImmutableList.of(100L, 200L, 300L); + WorkerMetric workerMetric3 = WorkerMetric.create(props3, stat3, false); + ImmutableSet expectedPids = ImmutableSet.of(100L, 200L, 300L); ImmutableMap propsMap = ImmutableMap.of( 1, props1, 2, props2); - ImmutableMap statsMap = + ImmutableMap memoryUsageMap = ImmutableMap.of( - 100L, stat1, - 200L, stat2); + 100L, stat1.getUsedMemoryInKB(), + 200L, stat2.getUsedMemoryInKB()); + WorkerMetricsCollector.MemoryCollectionResult memoryCollectionResult = + new WorkerMetricsCollector.MemoryCollectionResult(memoryUsageMap, collectionTime); ImmutableList expectedMetrics = ImmutableList.of(workerMetric1, workerMetric2, workerMetric3); - when(spyCollector.collectStats(any(), pidsCaptor.capture())).thenReturn(statsMap); + when(spyCollector.collectMemoryUsageByPid(any(), pidsCaptor.capture())) + .thenReturn(memoryCollectionResult); + clock.setTime(registrationTime.toEpochMilli()); spyCollector.registerWorker(props1); spyCollector.registerWorker(props2); @@ -205,4 +224,24 @@ public void testcollectMetrics() throws Exception { assertThat(metrics).containsExactlyElementsIn(expectedMetrics); assertThat(spyCollector.getWorkerIdToWorkerProperties()).isEqualTo(propsMap); } + + private static class ManualClock implements Clock { + private long currentTime = 0L; + + ManualClock() {} + + @Override + public long nanoTime() { + throw new AssertionError("unexpected method call"); + } + + @Override + public long currentTimeMillis() { + return currentTime; + } + + void setTime(long currentTime) { + this.currentTime = currentTime; + } + } } diff --git a/src/test/java/com/google/devtools/build/lib/worker/WorkerSpawnRunnerTest.java b/src/test/java/com/google/devtools/build/lib/worker/WorkerSpawnRunnerTest.java index 8887e579d74ce6..5044c0812952ea 100644 --- a/src/test/java/com/google/devtools/build/lib/worker/WorkerSpawnRunnerTest.java +++ b/src/test/java/com/google/devtools/build/lib/worker/WorkerSpawnRunnerTest.java @@ -42,6 +42,7 @@ import com.google.devtools.build.lib.actions.SpawnMetrics; import com.google.devtools.build.lib.actions.UserExecException; import com.google.devtools.build.lib.actions.cache.VirtualActionInput; +import com.google.devtools.build.lib.clock.JavaClock; import com.google.devtools.build.lib.collect.nestedset.NestedSetBuilder; import com.google.devtools.build.lib.collect.nestedset.Order; import com.google.devtools.build.lib.events.ExtendedEventHandler; @@ -153,7 +154,8 @@ public void testExecInWorker_happyPath() throws ExecException, InterruptedExcept /* runfilesTreeUpdater= */ null, options, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); when(worker.getResponse(0)) @@ -203,7 +205,8 @@ public void testExecInWorker_virtualInputs_doesntQueryInputFileCache() /* runfilesTreeUpdater= */ null, options, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); @@ -262,7 +265,8 @@ public void testExecInWorker_finishesAsyncOnInterrupt() /* runfilesTreeUpdater=*/ null, options, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); when(worker.getResponse(anyInt())) @@ -311,7 +315,8 @@ public void testExecInWorker_sendsCancelMessageOnInterrupt() /* runfilesTreeUpdater=*/ null, workerOptions, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); Semaphore secondResponseRequested = new Semaphore(0); @@ -375,7 +380,8 @@ public void testExecInWorker_unsandboxedDiesOnInterrupt() /* runfilesTreeUpdater=*/ null, workerOptions, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); when(worker.getResponse(anyInt())).thenThrow(new InterruptedException()); @@ -425,7 +431,8 @@ public void testExecInWorker_noMultiplexWithDynamic() /* runfilesTreeUpdater= */ null, workerOptions, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); // This worker key just so happens to be multiplex and require sandboxing. WorkerKey key = createWorkerKey(WorkerProtocolFormat.JSON, fs, true); Path logFile = fs.getPath("/worker.log"); @@ -472,7 +479,8 @@ private void assertRecordedResponsethrowsException( /* runfilesTreeUpdater= */ null, workerOptions, metricsCollector, - SyscallCache.NO_CACHE); + SyscallCache.NO_CACHE, + new JavaClock()); WorkerKey key = createWorkerKey(fs, "mnem", false); Path logFile = fs.getPath("/worker.log"); when(worker.getLogFile()).thenReturn(logFile);