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 f75acd485a3fac..7386899da99a7c 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 @@ -22,6 +22,8 @@ public abstract class MemoryPressureEvent { public abstract boolean wasManualGc(); + public abstract boolean wasGcLockerInitiatedGc(); + public abstract boolean wasFullGc(); public abstract long tenuredSpaceUsedBytes(); @@ -30,7 +32,10 @@ public abstract class MemoryPressureEvent { @VisibleForTesting public static Builder newBuilder() { - return new AutoValue_MemoryPressureEvent.Builder().setWasFullGc(false); + return new AutoValue_MemoryPressureEvent.Builder() + .setWasManualGc(false) + .setWasGcLockerInitiatedGc(false) + .setWasFullGc(false); } /** A memory pressure event builder. */ @@ -39,6 +44,8 @@ public static Builder newBuilder() { public abstract static class Builder { public abstract Builder setWasManualGc(boolean value); + public abstract Builder setWasGcLockerInitiatedGc(boolean value); + public abstract Builder setWasFullGc(boolean value); public abstract Builder setTenuredSpaceUsedBytes(long value); diff --git a/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureListener.java b/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureListener.java index 181a634b312213..4367453af7d561 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureListener.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureListener.java @@ -119,6 +119,7 @@ public void handleNotification(Notification notification, Object handback) { MemoryPressureEvent event = MemoryPressureEvent.newBuilder() .setWasManualGc(gcInfo.getGcCause().equals("System.gc()")) + .setWasGcLockerInitiatedGc(gcInfo.getGcCause().equals("GCLocker Initiated GC")) .setWasFullGc(GarbageCollectionMetricsUtils.isFullGc(gcInfo)) .setTenuredSpaceUsedBytes(tenuredSpaceUsedBytes) .setTenuredSpaceMaxBytes(tenuredSpaceMaxBytes) 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 1d3531d84a1b0f..b41161ae47ec12 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 @@ -101,6 +101,7 @@ public void handle(MemoryPressureEvent event) { } boolean wasHeapLimiterTriggeredGc = false; + boolean wasGcLockerDeferredHeapLimiterTriggeredGc = false; if (event.wasManualGc()) { wasHeapLimiterTriggeredGc = heapLimiterTriggeredGc.getAndSet(false); if (!wasHeapLimiterTriggeredGc) { @@ -108,6 +109,17 @@ public void handle(MemoryPressureEvent event) { logger.atInfo().log("Ignoring manual GC from other source"); return; } + } else if (event.wasGcLockerInitiatedGc() && heapLimiterTriggeredGc.getAndSet(false)) { + // If System.gc() is called was while there are JNI thread(s) in the critical region, GCLocker + // defers the GC until those threads exit the ciritical region. However, all GCLocker + // initiated GCs are minor evacuation pauses, so we won't get the full GC we requested. Cancel + // the timeout so we can attempt System.gc() again if we're still over the threshold. See + // full explanation in b/263405096#comment14. + logger.atWarning().log( + "Observed a GCLocker initiated GC without observing a manual GC since the last call to" + + " System.gc(), cancelling timeout to permit a retry"); + wasGcLockerDeferredHeapLimiterTriggeredGc = true; + lastTriggeredGcMillis.set(0); } // Get a local reference to guard against concurrent modifications. @@ -120,7 +132,7 @@ public void handle(MemoryPressureEvent event) { int actual = (int) ((event.tenuredSpaceUsedBytes() * 100L) / event.tenuredSpaceMaxBytes()); if (actual < threshold) { - if (wasHeapLimiterTriggeredGc) { + if (wasHeapLimiterTriggeredGc || wasGcLockerDeferredHeapLimiterTriggeredGc) { logger.atInfo().log("Back under threshold (%s%% of tenured space)", actual); } consecutiveIgnoredFullGcsOverThreshold.set(0); diff --git a/src/test/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiterTest.java b/src/test/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiterTest.java index 347e46bc161f9b..9ba856d97eb7c7 100644 --- a/src/test/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiterTest.java +++ b/src/test/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiterTest.java @@ -68,8 +68,8 @@ public void underThreshold_noOom() throws Exception { options.oomMoreEagerlyThreshold = 99; underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(100)); - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterOrganicFullGc(100)); + underTest.handle(percentUsedAfterManualGc(89)); verifyNoInteractions(bugReporter); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1)); @@ -81,9 +81,9 @@ public void overThreshold_oom() throws Exception { underTest.setOptions(options); // Triggers GC, and tells RetainedHeapLimiter to OOM if too much memory used next time. - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); ArgumentCaptor crashArgument = ArgumentCaptor.forClass(Crash.class); verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any()); @@ -100,15 +100,15 @@ public void inactiveAfterOom() throws Exception { options.minTimeBetweenTriggeredGc = Duration.ZERO; underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); verify(bugReporter).handleCrash(any(), any()); // No more GC or bug reports even if notifications come in after an OOM is in progress. WeakReference ref = new WeakReference<>(new Object()); clock.advanceMillis(Duration.ofMinutes(1).toMillis()); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); assertThat(ref.get()).isNotNull(); verifyNoMoreBugReports(); @@ -121,10 +121,10 @@ public void externalGcNoTrigger() throws Exception { underTest.setOptions(options); // No trigger because cause was "System.gc()". - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); // Proof: no OOM. - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); verifyNoInteractions(bugReporter); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0)); @@ -135,13 +135,13 @@ public void triggerReset() throws Exception { options.oomMoreEagerlyThreshold = 90; underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); // Got under the threshold, so no OOM. - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterManualGc(89)); // No OOM this time since wasn't triggered. - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); verifyNoInteractions(bugReporter); } @@ -150,9 +150,9 @@ public void triggerRaceWithOtherGc() throws Exception { options.oomMoreEagerlyThreshold = 90; underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterForcedGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(91)); ArgumentCaptor crashArgument = ArgumentCaptor.forClass(Crash.class); verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any()); @@ -166,13 +166,13 @@ public void minTimeBetweenGc_lessThan_noGc() throws Exception { underTest.setOptions(options); WeakReference ref = new WeakReference<>(new Object()); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); assertThat(ref.get()).isNull(); - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterManualGc(89)); ref = new WeakReference<>(new Object()); clock.advanceMillis(Duration.ofSeconds(59).toMillis()); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); assertThat(ref.get()).isNotNull(); assertStats( @@ -188,13 +188,13 @@ public void minTimeBetweenGc_greaterThan_gc() throws Exception { underTest.setOptions(options); WeakReference ref = new WeakReference<>(new Object()); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); assertThat(ref.get()).isNull(); - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterManualGc(89)); ref = new WeakReference<>(new Object()); clock.advanceMillis(Duration.ofSeconds(61).toMillis()); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); assertThat(ref.get()).isNull(); assertStats( @@ -203,34 +203,63 @@ public void minTimeBetweenGc_greaterThan_gc() throws Exception { .setMaxConsecutiveIgnoredGcsOverThreshold(0)); } + @Test + public void gcLockerDefersManualGc_timeoutCancelled() throws Exception { + options.oomMoreEagerlyThreshold = 90; + options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1); + underTest.setOptions(options); + + underTest.handle(percentUsedAfterOrganicFullGc(91)); + WeakReference ref = new WeakReference<>(new Object()); + underTest.handle(percentUsedAfterGcLockerGc(91)); + assertThat(ref.get()).isNull(); + + assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(2)); + } + + @Test + public void gcLockerAfterSuccessfulManualGc_timeoutPreserved() throws Exception { + options.oomMoreEagerlyThreshold = 90; + options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1); + underTest.setOptions(options); + + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(89)); + WeakReference ref = new WeakReference<>(new Object()); + underTest.handle(percentUsedAfterGcLockerGc(91)); + assertThat(ref.get()).isNotNull(); + + assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1)); + } + @Test public void reportsMaxConsecutiveIgnored() throws Exception { options.oomMoreEagerlyThreshold = 90; options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1); underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(89)); for (int i = 0; i < 6; i++) { - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); } clock.advanceMillis(Duration.ofMinutes(2).toMillis()); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterForcedGc(89)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterManualGc(89)); for (int i = 0; i < 8; i++) { - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); } - underTest.handle(percentUsedAfterOtherGc(89)); // Breaks the streak of over threshold events. - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(89)); // Breaks the streak of over threshold GCs. + underTest.handle(percentUsedAfterOrganicFullGc(91)); clock.advanceMillis(Duration.ofMinutes(2).toMillis()); - underTest.handle(percentUsedAfterOtherGc(91)); - underTest.handle(percentUsedAfterOtherGc(89)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(89)); for (int i = 0; i < 7; i++) { - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); } assertStats( @@ -245,7 +274,7 @@ public void threshold100_noGcTriggeredEvenWithNonsenseStats() throws Exception { underTest.setOptions(options); WeakReference ref = new WeakReference<>(new Object()); - underTest.handle(percentUsedAfterOtherGc(101)); + underTest.handle(percentUsedAfterOrganicFullGc(101)); assertThat(ref.get()).isNotNull(); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0)); @@ -253,7 +282,7 @@ public void threshold100_noGcTriggeredEvenWithNonsenseStats() throws Exception { @Test public void worksWithoutSettingOptions() { - underTest.handle(percentUsedAfterOtherGc(95)); + underTest.handle(percentUsedAfterOrganicFullGc(95)); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0)); } @@ -262,7 +291,7 @@ public void statsReset() throws Exception { options.oomMoreEagerlyThreshold = 90; underTest.setOptions(options); - underTest.handle(percentUsedAfterOtherGc(91)); + underTest.handle(percentUsedAfterOrganicFullGc(91)); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1)); assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0)); @@ -277,22 +306,23 @@ public void invalidThreshold_throws(@TestParameter({"-1", "101"}) int threshold) .isEqualTo(Code.EXPERIMENTAL_OOM_MORE_EAGERLY_THRESHOLD_INVALID_VALUE); } - private static MemoryPressureEvent percentUsedAfterForcedGc(int percentUsed) { - return percentUsedAfterGc(/* wasManualGc= */ true, percentUsed); + private static MemoryPressureEvent percentUsedAfterManualGc(int percentUsed) { + return percentUsedAfterGc(percentUsed).setWasManualGc(true).setWasFullGc(true).build(); + } + + private static MemoryPressureEvent percentUsedAfterOrganicFullGc(int percentUsed) { + return percentUsedAfterGc(percentUsed).setWasFullGc(true).build(); } - private static MemoryPressureEvent percentUsedAfterOtherGc(int percentUsed) { - return percentUsedAfterGc(/* wasManualGc= */ false, percentUsed); + private static MemoryPressureEvent percentUsedAfterGcLockerGc(int percentUsed) { + return percentUsedAfterGc(percentUsed).setWasGcLockerInitiatedGc(true).build(); } - private static MemoryPressureEvent percentUsedAfterGc(boolean wasManualGc, int percentUsed) { + private static MemoryPressureEvent.Builder percentUsedAfterGc(int percentUsed) { checkArgument(percentUsed >= 0, percentUsed); return MemoryPressureEvent.newBuilder() - .setWasManualGc(wasManualGc) - .setWasFullGc(true) .setTenuredSpaceUsedBytes(percentUsed) - .setTenuredSpaceMaxBytes(100L) - .build(); + .setTenuredSpaceMaxBytes(100L); } private void assertStats(MemoryPressureStats.Builder expected) {