-
Bug
-
Resolution: Fixed
-
P3
-
7u60, 8, 8u20, 8u40, 9, 11, 13
-
b08
Issue | Fix Version | Assignee | Priority | Status | Resolution | Resolved In Build |
---|---|---|---|---|---|---|
JDK-8245298 | 13.0.4 | Kim Barrett | P3 | Resolved | Fixed | b02 |
JDK-8229114 | 11.0.6-oracle | Fairoz Matte | P3 | Resolved | Fixed | b01 |
JDK-8232099 | 11.0.6 | Kim Barrett | P3 | Resolved | Fixed | b01 |
JDK-8234690 | openjdk8u242 | Kim Barrett | P3 | Resolved | Fixed | team |
JDK-8235552 | openjdk8u232 | Kim Barrett | P3 | Resolved | Fixed | master |
JDK-8229021 | 8u241 | Fairoz Matte | P3 | Resolved | Fixed | b01 |
JDK-8231651 | 8u231 | Fairoz Matte | P3 | Resolved | Fixed | b31 |
JDK-8229410 | 8u221 | Fairoz Matte | P3 | Closed | Fixed | b35 |
JDK-8234991 | emb-8u241 | Fairoz Matte | P3 | Resolved | Fixed | team |
Here's an example of this (with ParNew):
{Heap before GC invocations=2 (full 0):
par new generation total 471872K, used 433003K [0x00000007bae00000, 0x00000007dae00000, 0x00000007dae00000)
eden space 419456K, 100% used [0x00000007bae00000, 0x00000007d47a0000, 0x00000007d47a0000)
from space 52416K, 25% used [0x00000007d47a0000, 0x00000007d54dacb0, 0x00000007d7ad0000)
to space 52416K, 0% used [0x00000007d7ad0000, 0x00000007d7ad0000, 0x00000007dae00000)
tenured generation total 524288K, used 0K [0x00000007dae00000, 0x00000007fae00000, 0x00000007fae00000)
the space 524288K, 0% used [0x00000007dae00000, 0x00000007dae00000, 0x00000007dae00200, 0x00000007fae00000)
compacting perm gen total 21248K, used 2549K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
the space 21248K, 12% used [0x00000007fae00000, 0x00000007fb07d7a0, 0x00000007fb07d800, 0x00000007fc2c0000)
No shared spaces configured.
1.119: [GC (Allocation Failure)[ParNew: 433003K->15843K(471872K), 0.0103090 secs] 433003K->15843K(996160K), 0.0103320 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
Heap after GC invocations=3 (full 0):
par new generation total 471872K, used 15843K [0x00000007bae00000, 0x00000007dae00000, 0x00000007dae00000)
eden space 419456K, 0% used [0x00000007bae00000, 0x00000007bae00000, 0x00000007d47a0000)
from space 52416K, 30% used [0x00000007d7ad0000, 0x00000007d8a48c88, 0x00000007dae00000)
to space 52416K, 0% used [0x00000007d47a0000, 0x00000007d47a0000, 0x00000007d7ad0000)
tenured generation total 524288K, used 0K [0x00000007dae00000, 0x00000007fae00000, 0x00000007fae00000)
the space 524288K, 0% used [0x00000007dae00000, 0x00000007dae00000, 0x00000007dae00200, 0x00000007fae00000)
compacting perm gen total 21248K, used 2549K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
the space 21248K, 12% used [0x00000007fae00000, 0x00000007fb07d7a0, 0x00000007fb07d800, 0x00000007fc2c0000)
No shared spaces configured.
}
{Heap before GC invocations=3 (full 0):
par new generation total 471872K, used 24002K [0x00000007bae00000, 0x00000007dae00000, 0x00000007dae00000)
eden space 419456K, 1% used [0x00000007bae00000, 0x00000007bb5f7c50, 0x00000007d47a0000)
from space 52416K, 30% used [0x00000007d7ad0000, 0x00000007d8a48c88, 0x00000007dae00000)
to space 52416K, 0% used [0x00000007d47a0000, 0x00000007d47a0000, 0x00000007d7ad0000)
tenured generation total 524288K, used 0K [0x00000007dae00000, 0x00000007fae00000, 0x00000007fae00000)
the space 524288K, 0% used [0x00000007dae00000, 0x00000007dae00000, 0x00000007dae00200, 0x00000007fae00000)
compacting perm gen total 21248K, used 2549K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
the space 21248K, 12% used [0x00000007fae00000, 0x00000007fb07d7a0, 0x00000007fb07d800, 0x00000007fc2c0000)
No shared spaces configured.
1.130: [GC (GCLocker Initiated GC)[ParNew: 24002K->12748K(471872K), 0.0123930 secs] 24002K->12748K(996160K), 0.0124130 secs] [Times: user=0.04 sys=0.01, real=0.01 secs]
Heap after GC invocations=4 (full 0):
par new generation total 471872K, used 12748K [0x00000007bae00000, 0x00000007dae00000, 0x00000007dae00000)
eden space 419456K, 0% used [0x00000007bae00000, 0x00000007bae00000, 0x00000007d47a0000)
from space 52416K, 24% used [0x00000007d47a0000, 0x00000007d5413320, 0x00000007d7ad0000)
to space 52416K, 0% used [0x00000007d7ad0000, 0x00000007d7ad0000, 0x00000007dae00000)
tenured generation total 524288K, used 0K [0x00000007dae00000, 0x00000007fae00000, 0x00000007fae00000)
the space 524288K, 0% used [0x00000007dae00000, 0x00000007dae00000, 0x00000007dae00200, 0x00000007fae00000)
compacting perm gen total 21248K, used 2549K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
the space 21248K, 12% used [0x00000007fae00000, 0x00000007fb07d7a0, 0x00000007fb07d800, 0x00000007fc2c0000)
No shared spaces configured.
}
Notice that:
* The timestamp of the second GC (1.130) is almost equal to the timestamp of the first GC plus the duration of the first GC (1.119 + 0.0103320 = 1.1293). In this test young GCs normally happen at a frequency of one every 100ms-110ms or so.
* The eden at the start of the second GC is almost empty (1% occupancy). We've also seen it very often with a completely empty eden.
* (the big hint) The second GC is GClocker-initiated.
This happens most often with ParNew (in some cases, more than 30% of the GCs are those unnecessary ones) but also happens with ParallelGC too but less frequently (maybe 1%-1.5% of the GCs are those unnecessary ones). I was unable to reproduce it with G1.
I can reproduce it with with latest JDK 7, JDK 8, and also the latest hotspot-gc/hotspot workspace. I haven't tried with JDK 6.
- backported by
-
JDK-8229021 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8229114 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8231651 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8232099 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8234690 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8234991 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8235552 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8245298 Unnecessary GCLocker-initiated young GCs
- Resolved
-
JDK-8229410 Unnecessary GCLocker-initiated young GCs
- Closed
- relates to
-
JDK-8229120 Intermittent gc/stress/gclocker/TestExcessGCLockerCollections.java test failures
- Open
-
JDK-7143858 G1: Back to back young GCs with the second GC having a minimally sized eden
- Resolved
-
JDK-8057586 Explicit GC ignored if GCLocker is active
- Resolved
-
JDK-8228965 VM_GenCollectFull is not always a full collection
- Open
-
JDK-8228964 Improve G1 GCLocker allocation stall
- Closed
-
JDK-8192647 GClocker induced GCs can starve threads requiring memory leading to OOME
- Open
-
JDK-8057573 CMSScavengeBeforeRemark ignored if GCLocker is active
- Closed