-
Bug
-
Resolution: Other
-
P2
-
1.3.1_02
-
01
-
x86, sparc
-
solaris_8, windows_nt
Issue | Fix Version | Assignee | Priority | Status | Resolution | Resolved In Build |
---|---|---|---|---|---|---|
JDK-2050407 | 1.4.1 | Jane Loizeaux | P2 | Closed | Other | hopper |
The customer is seeing their application go into long bouts of Full GCs, bringing their large application to a standstill. They have now been able to provide a testcase, and demonstration settings and output from a debug jvm (attached). Here's the end a Test output:
loop 55 39976960 166784 39810176
[Full GC 40776K->19469K(20160K), 0.2886160 secs]
[Full GC 19981K->19469K(19712K), 5.8652228 secs]
loop 56 27197440 122216 27075224
loop 57 36831232 147968 36683264
[Full GC 40776K->19469K(20160K), 0.2903560 secs]
[Full GC 19981K->19469K(19712K), 0.2947036 secs]
loop 58 24117248 168936 23948312
loop 59 33685504 129192 33556312
[Full GC 40776K->19469K(20160K), 0.2875250 secs]
[Full GC 19981K->19469K(19712K), 0.2930166 secs]
loop 60 20971520 150120 20821400
loop 61 30605312 175848 30429464
loop 62 40173568 136128 40037440
[Full GC 40776K->19469K(20160K), 0.2924913 secs]
[Full GC 19981K->19469K(19712K), 0.2949892 secs]
loop 63 27459584 157032 27302552
loop 64 37093376 182784 36910592
[Full GC 40776K->19469K(20160K), 0.2890132 secs]
[Full GC 19981K->19469K(19712K), 0.2955358 secs]
loop 65 24313856 138216 24175640
loop 66 33947648 163968 33783680
[Full GC 40776K->19469K(20160K), 0.2897438 secs]
[Full GC 19981K->19469K(19712K), 0.2984033 secs]
loop 67 21168128 119400 21048728
loop 68 30801920 145152 30656768
loop 69 40435712 170944 40264768
[Full GC 40776K->19469K(20160K), 0.2919497 secs]
[Full GC 19981K->19469K(19712K), 0.2915988 secs]
In their actual application, they've seen Full GC's take nearly a minute, freeing 300M each time. They go on to say:
I've been playing about with a bit more. Running with jdk1.4.0-beta3,
I find that, as I increase the first parameter, the behaviour switches
from good to bad at this point:
C:\jdk1.4.0-beta3\bin\java.exe -mx40M -Xincgc -verbose:gc -classpath
C:\projects\ideatest Test 2391840 50000 50
i.e. 2391800 is fine 2391840 collapses into continual gcs.
loop 55 39976960 166784 39810176
[Full GC 40776K->19469K(20160K), 0.2886160 secs]
[Full GC 19981K->19469K(19712K), 5.8652228 secs]
loop 56 27197440 122216 27075224
loop 57 36831232 147968 36683264
[Full GC 40776K->19469K(20160K), 0.2903560 secs]
[Full GC 19981K->19469K(19712K), 0.2947036 secs]
loop 58 24117248 168936 23948312
loop 59 33685504 129192 33556312
[Full GC 40776K->19469K(20160K), 0.2875250 secs]
[Full GC 19981K->19469K(19712K), 0.2930166 secs]
loop 60 20971520 150120 20821400
loop 61 30605312 175848 30429464
loop 62 40173568 136128 40037440
[Full GC 40776K->19469K(20160K), 0.2924913 secs]
[Full GC 19981K->19469K(19712K), 0.2949892 secs]
loop 63 27459584 157032 27302552
loop 64 37093376 182784 36910592
[Full GC 40776K->19469K(20160K), 0.2890132 secs]
[Full GC 19981K->19469K(19712K), 0.2955358 secs]
loop 65 24313856 138216 24175640
loop 66 33947648 163968 33783680
[Full GC 40776K->19469K(20160K), 0.2897438 secs]
[Full GC 19981K->19469K(19712K), 0.2984033 secs]
loop 67 21168128 119400 21048728
loop 68 30801920 145152 30656768
loop 69 40435712 170944 40264768
[Full GC 40776K->19469K(20160K), 0.2919497 secs]
[Full GC 19981K->19469K(19712K), 0.2915988 secs]
In their actual application, they've seen Full GC's take nearly a minute, freeing 300M each time. They go on to say:
I've been playing about with a bit more. Running with jdk1.4.0-beta3,
I find that, as I increase the first parameter, the behaviour switches
from good to bad at this point:
C:\jdk1.4.0-beta3\bin\java.exe -mx40M -Xincgc -verbose:gc -classpath
C:\projects\ideatest Test 2391840 50000 50
i.e. 2391800 is fine 2391840 collapses into continual gcs.
- backported by
-
JDK-2050407 Repetitive Full Garbage Collections occuring with -Xincgc
- Closed
- relates to
-
JDK-4459148 Incremental GC has delays upto 13 seconds under jdk1.2.2 / 1.3.1 / 1.4.0-b64
- Closed