Skip to content

Commit

Permalink
Detect when GCLocker defers a System.gc() call.
Browse files Browse the repository at this point in the history
It will be downgraded to a minor GC. Cancel the `RetainedHeapLimiter` timeout so we can attempt a full GC again.

PiperOrigin-RevId: 519734506
Change-Id: I7806d0232ef12d9e59176893c0da69f8f941b50f
  • Loading branch information
justinhorvitz authored and copybara-github committed Mar 27, 2023
1 parent 3c1c0c0 commit f4b3165
Show file tree
Hide file tree
Showing 4 changed files with 97 additions and 47 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@
public abstract class MemoryPressureEvent {
public abstract boolean wasManualGc();

public abstract boolean wasGcLockerInitiatedGc();

public abstract boolean wasFullGc();

public abstract long tenuredSpaceUsedBytes();
Expand All @@ -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. */
Expand All @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -101,13 +101,25 @@ public void handle(MemoryPressureEvent event) {
}

boolean wasHeapLimiterTriggeredGc = false;
boolean wasGcLockerDeferredHeapLimiterTriggeredGc = false;
if (event.wasManualGc()) {
wasHeapLimiterTriggeredGc = heapLimiterTriggeredGc.getAndSet(false);
if (!wasHeapLimiterTriggeredGc) {
// This was a manually triggered GC, but not from us earlier: short-circuit.
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.
Expand All @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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));
Expand All @@ -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<Crash> crashArgument = ArgumentCaptor.forClass(Crash.class);
verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any());
Expand All @@ -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();

Expand All @@ -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));
Expand All @@ -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);
}

Expand All @@ -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<Crash> crashArgument = ArgumentCaptor.forClass(Crash.class);
verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any());
Expand All @@ -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(
Expand All @@ -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(
Expand All @@ -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(
Expand All @@ -245,15 +274,15 @@ 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));
}

@Test
public void worksWithoutSettingOptions() {
underTest.handle(percentUsedAfterOtherGc(95));
underTest.handle(percentUsedAfterOrganicFullGc(95));
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0));
}

Expand All @@ -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));
Expand All @@ -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) {
Expand Down

0 comments on commit f4b3165

Please sign in to comment.