From a691e974d2e4c5fa4a469e1321b18d15ac7e9cfa Mon Sep 17 00:00:00 2001 From: Googler Date: Mon, 27 Mar 2023 14:15:15 -0700 Subject: [PATCH] Create a `GcThrashingDetector`. Unlike `RetainedHeapLimiter`, does not trigger manual GC. Can be configured with multiple limits, i.e. "OOM if there are X consecutive full GCs over threshold within Y seconds" for various values of X and Y. Maintains a sliding window for each limit. This may have some waste for overlapping windows, but in practice the limits are expected to be small and there won't be many of them. Not wired in via flags yet - will need to write a custom option converter. PiperOrigin-RevId: 519825944 Change-Id: Ifbc4391ebe088bfca9b9841baccc5bc0de992022 --- .../devtools/build/lib/clock/Clock.java | 21 +- .../lib/runtime/GcThrashingDetector.java | 128 ++++++++++ .../lib/runtime/MemoryPressureEvent.java | 4 + .../lib/runtime/RetainedHeapLimiter.java | 2 +- .../lib/runtime/GcThrashingDetectorTest.java | 228 ++++++++++++++++++ 5 files changed, 374 insertions(+), 9 deletions(-) create mode 100644 src/main/java/com/google/devtools/build/lib/runtime/GcThrashingDetector.java create mode 100644 src/test/java/com/google/devtools/build/lib/runtime/GcThrashingDetectorTest.java diff --git a/src/main/java/com/google/devtools/build/lib/clock/Clock.java b/src/main/java/com/google/devtools/build/lib/clock/Clock.java index ffec360efedce6..d72f640fa92f19 100644 --- a/src/main/java/com/google/devtools/build/lib/clock/Clock.java +++ b/src/main/java/com/google/devtools/build/lib/clock/Clock.java @@ -13,21 +13,26 @@ // limitations under the License. package com.google.devtools.build.lib.clock; -/** - * This class provides an interface for a pluggable clock. - */ +import java.time.Instant; + +/** Provides an interface for a pluggable clock. */ public interface Clock { /** - * Returns the current time in milliseconds. The milliseconds are counted from midnight - * Jan 1, 1970. + * Returns the current time in milliseconds. The milliseconds are counted from midnight Jan 1, + * 1970. */ long currentTimeMillis(); /** - * Returns the current time in nanoseconds. The nanoseconds are measured relative to some - * unknown, but fixed event. Unfortunately, a sequence of calls to this method is *not* - * guaranteed to return non-decreasing values, so callers should be tolerant to this behavior. + * Returns the current time in nanoseconds. The nanoseconds are measured relative to some unknown, + * but fixed event. Unfortunately, a sequence of calls to this method is *not* guaranteed to + * return non-decreasing values, so callers should be tolerant to this behavior. */ long nanoTime(); + + /** Returns {@link #currentTimeMillis} as an {@link Instant}. */ + default Instant now() { + return Instant.ofEpochMilli(currentTimeMillis()); + } } diff --git a/src/main/java/com/google/devtools/build/lib/runtime/GcThrashingDetector.java b/src/main/java/com/google/devtools/build/lib/runtime/GcThrashingDetector.java new file mode 100644 index 00000000000000..af666dad5055df --- /dev/null +++ b/src/main/java/com/google/devtools/build/lib/runtime/GcThrashingDetector.java @@ -0,0 +1,128 @@ +// Copyright 2023 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.runtime; + +import static com.google.common.base.Preconditions.checkArgument; +import static com.google.common.collect.ImmutableList.toImmutableList; + +import com.google.auto.value.AutoValue; +import com.google.common.collect.ImmutableList; +import com.google.common.flogger.GoogleLogger; +import com.google.devtools.build.lib.bugreport.BugReporter; +import com.google.devtools.build.lib.bugreport.Crash; +import com.google.devtools.build.lib.bugreport.CrashContext; +import com.google.devtools.build.lib.clock.Clock; +import java.time.Duration; +import java.time.Instant; +import java.util.ArrayDeque; +import java.util.List; +import java.util.Queue; + +/** + * Listens for {@link MemoryPressureEvent} to detect GC thrashing. + * + *

For each {@link Limit}, maintains a sliding window of the timestamps of consecutive full GCs + * within {@link Limit#period} where {@link MemoryPressureEvent#percentTenuredSpaceUsed} was more + * than {@link #threshold}. If {@link Limit#count} consecutive over-threshold full GCs within {@link + * Limit#period} are observed, calls {@link BugReporter#handleCrash} with an {@link + * OutOfMemoryError}. + * + *

Manual GCs do not contribute to the limit. This is to avoid OOMing on GCs manually triggered + * for memory metrics. + */ +final class GcThrashingDetector { + + private static final GoogleLogger logger = GoogleLogger.forEnclosingClass(); + + @AutoValue + abstract static class Limit { + abstract Duration period(); + + abstract int count(); + + static Limit of(Duration period, int count) { + checkArgument( + !period.isNegative() && !period.isZero(), "period must be positive: %s", period); + checkArgument(count > 0, "count must be positive: %s", count); + return new AutoValue_GcThrashingDetector_Limit(period, count); + } + } + + private final int threshold; + private final ImmutableList trackers; + private final Clock clock; + private final BugReporter bugReporter; + + GcThrashingDetector(int threshold, List limits, Clock clock, BugReporter bugReporter) { + this.threshold = threshold; + this.trackers = limits.stream().map(SingleLimitTracker::new).collect(toImmutableList()); + this.clock = clock; + this.bugReporter = bugReporter; + } + + void handle(MemoryPressureEvent event) { + if (event.percentTenuredSpaceUsed() < threshold) { + for (var tracker : trackers) { + tracker.underThresholdGc(); + } + return; + } + + if (!event.wasFullGc() || event.wasManualGc()) { + return; + } + + Instant now = clock.now(); + for (var tracker : trackers) { + tracker.overThresholdGc(now); + } + } + + /** Tracks GC history for a single {@link Limit}. */ + private final class SingleLimitTracker { + private final Duration period; + private final int count; + private final Queue window; + + SingleLimitTracker(Limit limit) { + this.period = limit.period(); + this.count = limit.count(); + this.window = new ArrayDeque<>(count); + } + + void underThresholdGc() { + window.clear(); + } + + void overThresholdGc(Instant now) { + Instant periodStart = now.minus(period); + while (!window.isEmpty() && window.element().isBefore(periodStart)) { + window.remove(); + } + window.add(now); + + if (window.size() == count) { + OutOfMemoryError oom = + new OutOfMemoryError( + String.format( + "GcThrashingDetector forcing exit: the tenured space has been more than %s%%" + + " occupied after %s consecutive full GCs within the past %s seconds.", + threshold, count, period.toSeconds())); + logger.atInfo().log("Calling handleCrash"); + bugReporter.handleCrash(Crash.from(oom), CrashContext.halt()); + } + } + } +} diff --git a/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureEvent.java b/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureEvent.java index 7386899da99a7c..238ea3bba6110c 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureEvent.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureEvent.java @@ -30,6 +30,10 @@ public abstract class MemoryPressureEvent { public abstract long tenuredSpaceMaxBytes(); + public final int percentTenuredSpaceUsed() { + return (int) ((tenuredSpaceUsedBytes() * 100L) / tenuredSpaceMaxBytes()); + } + @VisibleForTesting public static Builder newBuilder() { return new AutoValue_MemoryPressureEvent.Builder() diff --git a/src/main/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiter.java b/src/main/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiter.java index b41161ae47ec12..69c242ff43efb3 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiter.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiter.java @@ -130,7 +130,7 @@ public void handle(MemoryPressureEvent event) { return; // Inactive. } - int actual = (int) ((event.tenuredSpaceUsedBytes() * 100L) / event.tenuredSpaceMaxBytes()); + int actual = event.percentTenuredSpaceUsed(); if (actual < threshold) { if (wasHeapLimiterTriggeredGc || wasGcLockerDeferredHeapLimiterTriggeredGc) { logger.atInfo().log("Back under threshold (%s%% of tenured space)", actual); diff --git a/src/test/java/com/google/devtools/build/lib/runtime/GcThrashingDetectorTest.java b/src/test/java/com/google/devtools/build/lib/runtime/GcThrashingDetectorTest.java new file mode 100644 index 00000000000000..dbf9a56ec7ca0a --- /dev/null +++ b/src/test/java/com/google/devtools/build/lib/runtime/GcThrashingDetectorTest.java @@ -0,0 +1,228 @@ +// Copyright 2023 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.runtime; + +import static com.google.common.base.Preconditions.checkArgument; +import static com.google.common.truth.Truth.assertThat; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.verifyNoInteractions; +import static org.mockito.Mockito.verifyNoMoreInteractions; + +import com.google.common.collect.ImmutableList; +import com.google.devtools.build.lib.bugreport.BugReporter; +import com.google.devtools.build.lib.bugreport.Crash; +import com.google.devtools.build.lib.runtime.GcThrashingDetector.Limit; +import com.google.devtools.build.lib.testutil.ManualClock; +import com.google.errorprone.annotations.CanIgnoreReturnValue; +import com.google.testing.junit.testparameterinjector.TestParameter; +import com.google.testing.junit.testparameterinjector.TestParameterInjector; +import java.time.Duration; +import org.junit.After; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; +import org.mockito.ArgumentCaptor; + +/** Tests for {@link GcThrashingDetector}. */ +@RunWith(TestParameterInjector.class) +public final class GcThrashingDetectorTest { + + private final BugReporter bugReporter = mock(BugReporter.class); + private final ManualClock clock = new ManualClock(); + + private enum GcType { + ORGANIC_FULL, + MINOR, + MANUAL + } + + @Before + public void setClock() { + clock.advanceMillis(100000); + } + + @After + public void verifyNoMoreBugReports() { + verifyNoMoreInteractions(bugReporter); + } + + @Test + public void limitViolated_oom() { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(5)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyOom(); + } + + @Test + public void underThreshold_noOom() { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(89, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(5)); + detector.handle(percentUsedAfterGc(89, GcType.ORGANIC_FULL)); + + verifyNoOom(); + } + + @Test + public void limitViolatedAfterUnderThreshold_oom() { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(89, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(1)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(1)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyOom(); + } + + @Test + public void outsideOfPeriod_noOom() { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(11)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyNoOom(); + } + + @Test + public void backUnderThreshold_noOom(@TestParameter GcType type) { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(1)); + detector.handle(percentUsedAfterGc(89, type)); + clock.advance(Duration.ofSeconds(1)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyNoOom(); + } + + @Test + public void notOrganicFullGc_noOom(@TestParameter({"MINOR", "MANUAL"}) GcType type) { + GcThrashingDetector detector = + createDetector(/* threshold= */ 90, Limit.of(Duration.ofSeconds(10), 2)); + + detector.handle(percentUsedAfterGc(91, type)); + clock.advance(Duration.ofSeconds(5)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyNoOom(); + } + + @Test + public void multipleLimits_noneViolated_noOom() { + GcThrashingDetector detector = + createDetector( + /* threshold= */ 90, + Limit.of(Duration.ofSeconds(10), 2), + Limit.of(Duration.ofMinutes(1), 3)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(11)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(50)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyNoOom(); + } + + @Test + public void multipleLimits_firstViolated_oom() { + GcThrashingDetector detector = + createDetector( + /* threshold= */ 90, + Limit.of(Duration.ofSeconds(10), 2), + Limit.of(Duration.ofMinutes(1), 3)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(5)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyOomWithMessage("2 consecutive full GCs within the past 10 seconds"); + } + + @Test + public void multipleLimits_secondViolated_oom() { + GcThrashingDetector detector = + createDetector( + /* threshold= */ 90, + Limit.of(Duration.ofSeconds(10), 2), + Limit.of(Duration.ofMinutes(1), 3)); + + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(11)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + clock.advance(Duration.ofSeconds(11)); + detector.handle(percentUsedAfterGc(91, GcType.ORGANIC_FULL)); + + verifyOomWithMessage("3 consecutive full GCs within the past 60 seconds"); + } + + private GcThrashingDetector createDetector(int threshold, Limit... limits) { + return new GcThrashingDetector(threshold, ImmutableList.copyOf(limits), clock, bugReporter); + } + + @CanIgnoreReturnValue + private OutOfMemoryError verifyOom() { + ArgumentCaptor crashArgument = ArgumentCaptor.forClass(Crash.class); + verify(bugReporter).handleCrash(crashArgument.capture(), any()); + Throwable oom = crashArgument.getValue().getThrowable(); + assertThat(oom).isInstanceOf(OutOfMemoryError.class); + return (OutOfMemoryError) oom; + } + + private void verifyOomWithMessage(String message) { + OutOfMemoryError oom = verifyOom(); + assertThat(oom).hasMessageThat().contains(message); + } + + private void verifyNoOom() { + verifyNoInteractions(bugReporter); + } + + private static MemoryPressureEvent percentUsedAfterGc(int percentUsed, GcType type) { + checkArgument(percentUsed >= 0, percentUsed); + MemoryPressureEvent.Builder event = + MemoryPressureEvent.newBuilder() + .setTenuredSpaceUsedBytes(percentUsed) + .setTenuredSpaceMaxBytes(100L); + switch (type) { + case ORGANIC_FULL: + event.setWasFullGc(true); + break; + case MINOR: + break; + case MANUAL: + event.setWasManualGc(true).setWasFullGc(true); + break; + } + return event.build(); + } +}