Skip to content

Commit 05ca080

Browse files
justinhorvitzfweikert
authored andcommitted
Detect when GCLocker defers a System.gc() call.
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
1 parent 6edca24 commit 05ca080

File tree

4 files changed

+97
-47
lines changed

4 files changed

+97
-47
lines changed

src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureEvent.java

+8-1
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,8 @@
2222
public abstract class MemoryPressureEvent {
2323
public abstract boolean wasManualGc();
2424

25+
public abstract boolean wasGcLockerInitiatedGc();
26+
2527
public abstract boolean wasFullGc();
2628

2729
public abstract long tenuredSpaceUsedBytes();
@@ -30,7 +32,10 @@ public abstract class MemoryPressureEvent {
3032

3133
@VisibleForTesting
3234
public static Builder newBuilder() {
33-
return new AutoValue_MemoryPressureEvent.Builder().setWasFullGc(false);
35+
return new AutoValue_MemoryPressureEvent.Builder()
36+
.setWasManualGc(false)
37+
.setWasGcLockerInitiatedGc(false)
38+
.setWasFullGc(false);
3439
}
3540

3641
/** A memory pressure event builder. */
@@ -39,6 +44,8 @@ public static Builder newBuilder() {
3944
public abstract static class Builder {
4045
public abstract Builder setWasManualGc(boolean value);
4146

47+
public abstract Builder setWasGcLockerInitiatedGc(boolean value);
48+
4249
public abstract Builder setWasFullGc(boolean value);
4350

4451
public abstract Builder setTenuredSpaceUsedBytes(long value);

src/main/java/com/google/devtools/build/lib/runtime/MemoryPressureListener.java

+1
Original file line numberDiff line numberDiff line change
@@ -119,6 +119,7 @@ public void handleNotification(Notification notification, Object handback) {
119119
MemoryPressureEvent event =
120120
MemoryPressureEvent.newBuilder()
121121
.setWasManualGc(gcInfo.getGcCause().equals("System.gc()"))
122+
.setWasGcLockerInitiatedGc(gcInfo.getGcCause().equals("GCLocker Initiated GC"))
122123
.setWasFullGc(GarbageCollectionMetricsUtils.isFullGc(gcInfo))
123124
.setTenuredSpaceUsedBytes(tenuredSpaceUsedBytes)
124125
.setTenuredSpaceMaxBytes(tenuredSpaceMaxBytes)

src/main/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiter.java

+13-1
Original file line numberDiff line numberDiff line change
@@ -101,13 +101,25 @@ public void handle(MemoryPressureEvent event) {
101101
}
102102

103103
boolean wasHeapLimiterTriggeredGc = false;
104+
boolean wasGcLockerDeferredHeapLimiterTriggeredGc = false;
104105
if (event.wasManualGc()) {
105106
wasHeapLimiterTriggeredGc = heapLimiterTriggeredGc.getAndSet(false);
106107
if (!wasHeapLimiterTriggeredGc) {
107108
// This was a manually triggered GC, but not from us earlier: short-circuit.
108109
logger.atInfo().log("Ignoring manual GC from other source");
109110
return;
110111
}
112+
} else if (event.wasGcLockerInitiatedGc() && heapLimiterTriggeredGc.getAndSet(false)) {
113+
// If System.gc() is called was while there are JNI thread(s) in the critical region, GCLocker
114+
// defers the GC until those threads exit the ciritical region. However, all GCLocker
115+
// initiated GCs are minor evacuation pauses, so we won't get the full GC we requested. Cancel
116+
// the timeout so we can attempt System.gc() again if we're still over the threshold. See
117+
// full explanation in b/263405096#comment14.
118+
logger.atWarning().log(
119+
"Observed a GCLocker initiated GC without observing a manual GC since the last call to"
120+
+ " System.gc(), cancelling timeout to permit a retry");
121+
wasGcLockerDeferredHeapLimiterTriggeredGc = true;
122+
lastTriggeredGcMillis.set(0);
111123
}
112124

113125
// Get a local reference to guard against concurrent modifications.
@@ -120,7 +132,7 @@ public void handle(MemoryPressureEvent event) {
120132

121133
int actual = (int) ((event.tenuredSpaceUsedBytes() * 100L) / event.tenuredSpaceMaxBytes());
122134
if (actual < threshold) {
123-
if (wasHeapLimiterTriggeredGc) {
135+
if (wasHeapLimiterTriggeredGc || wasGcLockerDeferredHeapLimiterTriggeredGc) {
124136
logger.atInfo().log("Back under threshold (%s%% of tenured space)", actual);
125137
}
126138
consecutiveIgnoredFullGcsOverThreshold.set(0);

src/test/java/com/google/devtools/build/lib/runtime/RetainedHeapLimiterTest.java

+75-45
Original file line numberDiff line numberDiff line change
@@ -68,8 +68,8 @@ public void underThreshold_noOom() throws Exception {
6868
options.oomMoreEagerlyThreshold = 99;
6969
underTest.setOptions(options);
7070

71-
underTest.handle(percentUsedAfterOtherGc(100));
72-
underTest.handle(percentUsedAfterForcedGc(89));
71+
underTest.handle(percentUsedAfterOrganicFullGc(100));
72+
underTest.handle(percentUsedAfterManualGc(89));
7373

7474
verifyNoInteractions(bugReporter);
7575
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1));
@@ -81,9 +81,9 @@ public void overThreshold_oom() throws Exception {
8181
underTest.setOptions(options);
8282

8383
// Triggers GC, and tells RetainedHeapLimiter to OOM if too much memory used next time.
84-
underTest.handle(percentUsedAfterOtherGc(91));
84+
underTest.handle(percentUsedAfterOrganicFullGc(91));
8585

86-
underTest.handle(percentUsedAfterForcedGc(91));
86+
underTest.handle(percentUsedAfterManualGc(91));
8787

8888
ArgumentCaptor<Crash> crashArgument = ArgumentCaptor.forClass(Crash.class);
8989
verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any());
@@ -100,15 +100,15 @@ public void inactiveAfterOom() throws Exception {
100100
options.minTimeBetweenTriggeredGc = Duration.ZERO;
101101
underTest.setOptions(options);
102102

103-
underTest.handle(percentUsedAfterOtherGc(91));
104-
underTest.handle(percentUsedAfterForcedGc(91));
103+
underTest.handle(percentUsedAfterOrganicFullGc(91));
104+
underTest.handle(percentUsedAfterManualGc(91));
105105
verify(bugReporter).handleCrash(any(), any());
106106

107107
// No more GC or bug reports even if notifications come in after an OOM is in progress.
108108
WeakReference<?> ref = new WeakReference<>(new Object());
109109
clock.advanceMillis(Duration.ofMinutes(1).toMillis());
110-
underTest.handle(percentUsedAfterOtherGc(91));
111-
underTest.handle(percentUsedAfterForcedGc(91));
110+
underTest.handle(percentUsedAfterOrganicFullGc(91));
111+
underTest.handle(percentUsedAfterManualGc(91));
112112
assertThat(ref.get()).isNotNull();
113113
verifyNoMoreBugReports();
114114

@@ -121,10 +121,10 @@ public void externalGcNoTrigger() throws Exception {
121121
underTest.setOptions(options);
122122

123123
// No trigger because cause was "System.gc()".
124-
underTest.handle(percentUsedAfterForcedGc(91));
124+
underTest.handle(percentUsedAfterManualGc(91));
125125

126126
// Proof: no OOM.
127-
underTest.handle(percentUsedAfterForcedGc(91));
127+
underTest.handle(percentUsedAfterManualGc(91));
128128
verifyNoInteractions(bugReporter);
129129

130130
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0));
@@ -135,13 +135,13 @@ public void triggerReset() throws Exception {
135135
options.oomMoreEagerlyThreshold = 90;
136136
underTest.setOptions(options);
137137

138-
underTest.handle(percentUsedAfterOtherGc(91));
138+
underTest.handle(percentUsedAfterOrganicFullGc(91));
139139

140140
// Got under the threshold, so no OOM.
141-
underTest.handle(percentUsedAfterForcedGc(89));
141+
underTest.handle(percentUsedAfterManualGc(89));
142142

143143
// No OOM this time since wasn't triggered.
144-
underTest.handle(percentUsedAfterForcedGc(91));
144+
underTest.handle(percentUsedAfterManualGc(91));
145145
verifyNoInteractions(bugReporter);
146146
}
147147

@@ -150,9 +150,9 @@ public void triggerRaceWithOtherGc() throws Exception {
150150
options.oomMoreEagerlyThreshold = 90;
151151
underTest.setOptions(options);
152152

153-
underTest.handle(percentUsedAfterOtherGc(91));
154-
underTest.handle(percentUsedAfterOtherGc(91));
155-
underTest.handle(percentUsedAfterForcedGc(91));
153+
underTest.handle(percentUsedAfterOrganicFullGc(91));
154+
underTest.handle(percentUsedAfterOrganicFullGc(91));
155+
underTest.handle(percentUsedAfterManualGc(91));
156156

157157
ArgumentCaptor<Crash> crashArgument = ArgumentCaptor.forClass(Crash.class);
158158
verify(bugReporter).handleCrash(crashArgument.capture(), ArgumentMatchers.any());
@@ -166,13 +166,13 @@ public void minTimeBetweenGc_lessThan_noGc() throws Exception {
166166
underTest.setOptions(options);
167167
WeakReference<?> ref = new WeakReference<>(new Object());
168168

169-
underTest.handle(percentUsedAfterOtherGc(91));
169+
underTest.handle(percentUsedAfterOrganicFullGc(91));
170170
assertThat(ref.get()).isNull();
171-
underTest.handle(percentUsedAfterForcedGc(89));
171+
underTest.handle(percentUsedAfterManualGc(89));
172172

173173
ref = new WeakReference<>(new Object());
174174
clock.advanceMillis(Duration.ofSeconds(59).toMillis());
175-
underTest.handle(percentUsedAfterOtherGc(91));
175+
underTest.handle(percentUsedAfterOrganicFullGc(91));
176176
assertThat(ref.get()).isNotNull();
177177

178178
assertStats(
@@ -188,13 +188,13 @@ public void minTimeBetweenGc_greaterThan_gc() throws Exception {
188188
underTest.setOptions(options);
189189
WeakReference<?> ref = new WeakReference<>(new Object());
190190

191-
underTest.handle(percentUsedAfterOtherGc(91));
191+
underTest.handle(percentUsedAfterOrganicFullGc(91));
192192
assertThat(ref.get()).isNull();
193-
underTest.handle(percentUsedAfterForcedGc(89));
193+
underTest.handle(percentUsedAfterManualGc(89));
194194

195195
ref = new WeakReference<>(new Object());
196196
clock.advanceMillis(Duration.ofSeconds(61).toMillis());
197-
underTest.handle(percentUsedAfterOtherGc(91));
197+
underTest.handle(percentUsedAfterOrganicFullGc(91));
198198
assertThat(ref.get()).isNull();
199199

200200
assertStats(
@@ -203,34 +203,63 @@ public void minTimeBetweenGc_greaterThan_gc() throws Exception {
203203
.setMaxConsecutiveIgnoredGcsOverThreshold(0));
204204
}
205205

206+
@Test
207+
public void gcLockerDefersManualGc_timeoutCancelled() throws Exception {
208+
options.oomMoreEagerlyThreshold = 90;
209+
options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1);
210+
underTest.setOptions(options);
211+
212+
underTest.handle(percentUsedAfterOrganicFullGc(91));
213+
WeakReference<?> ref = new WeakReference<>(new Object());
214+
underTest.handle(percentUsedAfterGcLockerGc(91));
215+
assertThat(ref.get()).isNull();
216+
217+
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(2));
218+
}
219+
220+
@Test
221+
public void gcLockerAfterSuccessfulManualGc_timeoutPreserved() throws Exception {
222+
options.oomMoreEagerlyThreshold = 90;
223+
options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1);
224+
underTest.setOptions(options);
225+
226+
underTest.handle(percentUsedAfterOrganicFullGc(91));
227+
underTest.handle(percentUsedAfterManualGc(89));
228+
WeakReference<?> ref = new WeakReference<>(new Object());
229+
underTest.handle(percentUsedAfterGcLockerGc(91));
230+
assertThat(ref.get()).isNotNull();
231+
232+
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1));
233+
}
234+
206235
@Test
207236
public void reportsMaxConsecutiveIgnored() throws Exception {
208237
options.oomMoreEagerlyThreshold = 90;
209238
options.minTimeBetweenTriggeredGc = Duration.ofMinutes(1);
210239
underTest.setOptions(options);
211240

212-
underTest.handle(percentUsedAfterOtherGc(91));
213-
underTest.handle(percentUsedAfterForcedGc(89));
241+
underTest.handle(percentUsedAfterOrganicFullGc(91));
242+
underTest.handle(percentUsedAfterManualGc(89));
214243
for (int i = 0; i < 6; i++) {
215-
underTest.handle(percentUsedAfterOtherGc(91));
244+
underTest.handle(percentUsedAfterOrganicFullGc(91));
216245
}
217246

218247
clock.advanceMillis(Duration.ofMinutes(2).toMillis());
219248

220-
underTest.handle(percentUsedAfterOtherGc(91));
221-
underTest.handle(percentUsedAfterForcedGc(89));
249+
underTest.handle(percentUsedAfterOrganicFullGc(91));
250+
underTest.handle(percentUsedAfterManualGc(89));
222251
for (int i = 0; i < 8; i++) {
223-
underTest.handle(percentUsedAfterOtherGc(91));
252+
underTest.handle(percentUsedAfterOrganicFullGc(91));
224253
}
225-
underTest.handle(percentUsedAfterOtherGc(89)); // Breaks the streak of over threshold events.
226-
underTest.handle(percentUsedAfterOtherGc(91));
254+
underTest.handle(percentUsedAfterOrganicFullGc(89)); // Breaks the streak of over threshold GCs.
255+
underTest.handle(percentUsedAfterOrganicFullGc(91));
227256

228257
clock.advanceMillis(Duration.ofMinutes(2).toMillis());
229258

230-
underTest.handle(percentUsedAfterOtherGc(91));
231-
underTest.handle(percentUsedAfterOtherGc(89));
259+
underTest.handle(percentUsedAfterOrganicFullGc(91));
260+
underTest.handle(percentUsedAfterOrganicFullGc(89));
232261
for (int i = 0; i < 7; i++) {
233-
underTest.handle(percentUsedAfterOtherGc(91));
262+
underTest.handle(percentUsedAfterOrganicFullGc(91));
234263
}
235264

236265
assertStats(
@@ -245,15 +274,15 @@ public void threshold100_noGcTriggeredEvenWithNonsenseStats() throws Exception {
245274
underTest.setOptions(options);
246275
WeakReference<?> ref = new WeakReference<>(new Object());
247276

248-
underTest.handle(percentUsedAfterOtherGc(101));
277+
underTest.handle(percentUsedAfterOrganicFullGc(101));
249278
assertThat(ref.get()).isNotNull();
250279

251280
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0));
252281
}
253282

254283
@Test
255284
public void worksWithoutSettingOptions() {
256-
underTest.handle(percentUsedAfterOtherGc(95));
285+
underTest.handle(percentUsedAfterOrganicFullGc(95));
257286
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0));
258287
}
259288

@@ -262,7 +291,7 @@ public void statsReset() throws Exception {
262291
options.oomMoreEagerlyThreshold = 90;
263292
underTest.setOptions(options);
264293

265-
underTest.handle(percentUsedAfterOtherGc(91));
294+
underTest.handle(percentUsedAfterOrganicFullGc(91));
266295

267296
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(1));
268297
assertStats(MemoryPressureStats.newBuilder().setManuallyTriggeredGcs(0));
@@ -277,22 +306,23 @@ public void invalidThreshold_throws(@TestParameter({"-1", "101"}) int threshold)
277306
.isEqualTo(Code.EXPERIMENTAL_OOM_MORE_EAGERLY_THRESHOLD_INVALID_VALUE);
278307
}
279308

280-
private static MemoryPressureEvent percentUsedAfterForcedGc(int percentUsed) {
281-
return percentUsedAfterGc(/* wasManualGc= */ true, percentUsed);
309+
private static MemoryPressureEvent percentUsedAfterManualGc(int percentUsed) {
310+
return percentUsedAfterGc(percentUsed).setWasManualGc(true).setWasFullGc(true).build();
311+
}
312+
313+
private static MemoryPressureEvent percentUsedAfterOrganicFullGc(int percentUsed) {
314+
return percentUsedAfterGc(percentUsed).setWasFullGc(true).build();
282315
}
283316

284-
private static MemoryPressureEvent percentUsedAfterOtherGc(int percentUsed) {
285-
return percentUsedAfterGc(/* wasManualGc= */ false, percentUsed);
317+
private static MemoryPressureEvent percentUsedAfterGcLockerGc(int percentUsed) {
318+
return percentUsedAfterGc(percentUsed).setWasGcLockerInitiatedGc(true).build();
286319
}
287320

288-
private static MemoryPressureEvent percentUsedAfterGc(boolean wasManualGc, int percentUsed) {
321+
private static MemoryPressureEvent.Builder percentUsedAfterGc(int percentUsed) {
289322
checkArgument(percentUsed >= 0, percentUsed);
290323
return MemoryPressureEvent.newBuilder()
291-
.setWasManualGc(wasManualGc)
292-
.setWasFullGc(true)
293324
.setTenuredSpaceUsedBytes(percentUsed)
294-
.setTenuredSpaceMaxBytes(100L)
295-
.build();
325+
.setTenuredSpaceMaxBytes(100L);
296326
}
297327

298328
private void assertStats(MemoryPressureStats.Builder expected) {

0 commit comments

Comments
 (0)