jdk 1.4.2_17 promotion failure (fragmentation?)

[Y Srinivas Ramakrishna]

It's almost certainly fragmentation, although the extent of
fragmentation appears quite excessive. You have roughly 2.9 GB
of free space in the old generation at the point at which the
promotion failed. The scavenge preceding the one in which the
promotion failure occurred promoted almost nothing to the old
generation, so the expectation is that the failing scavenge would
also try to promote a pretty small amount of data. Thus, it would
seem that the 2.9 GB of free space in the old generation must be
excessively fragmented not to be able to absorb even that
small amount of promotion. Frankly, I am surprised at this
behaviour. Is there something inherent in your application
that causes the sizes and lifetimes of your longer-lived objects to
vary a lot over time?

Can you share with us a longer GC log and perhaps some data as to the
frequency of such promotion failure events? I'll cintact you off-line
for the GC logs.

-- ramki

----- Original Message -----
From: Mike Finn <mike at mikefinn.com>
Date: Monday, August 11, 2008 11:48 am
Subject: jdk 1.4.2_17 promotion failure (fragmentation?)
To: hotspot-gc-use at openjdk.java.net


> We have a large, long running server application running in Weblogic 
> (using jdk 1.4.2_17) and using CMS.
> 
> We originally were running in 32-bit mode and were getting promotion 
> failures and concurrent mode failures. When this happened, there was 
> usually a good amount of tenured space free, so we thought that the 
> problem was with fragmentation of the free space in the tenured generation.
> 
> To fix that, we've tried increasing the heap size. We have kept upping 
> 
> the heap size (moving to 64-bit to do so) and now have a heap size of 
> 
> 14G (see command line options below). The problem persisted and we 
> experimented with lowering the newsize to try to reduce the 
> requirement 
> for contiguous space in tenured space, but we still promotion failures 
> 
> (see log snippet at the end of this email).
> 
> Is there anything else we can do in regards to tuning (lower the 
> CMSInitiatingOccupancyFraction?) ? Or are we going to have to move to 
> a 
> newer JDK? Or is it still possible that we have a memory leak or some 
> 
> other abberrant program behavior?
> 
> /j2sdk1.4.2_17/bin/java -server -XX:CMSInitiatingOccupancyFraction=70 
> 
> -XX:NewSize=320m -XX:MaxNewSize=320m -XX:SurvivorRatio=8 
> -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:PermSize=96m 
> -XX:MaxPermSize=96m -XX:MaxTenuringThreshold=5 -Xms14336m -Xmx14336m 
> -Xss256k -XX:+HandlePromotionFailure -XX:+PrintTenuringDistribution -d64
> 
> 
> 
> 265150.609: [GC  {Heap before GC invocations=57327:
> Heap
>  par new generation   total 294912K, used 273751K [0xfffffffbef000000, 
> 
> 0xfffffffc03000000, 0xfffffffc03000000)
>   eden space 262144K, 100% used [0xfffffffbef000000, 
> 0xfffffffbff000000, 
> 0xfffffffbff000000)
>   from space 32768K,  35% used [0xfffffffc01000000, 
> 0xfffffffc01b55cf0, 
> 0xfffffffc03000000)
>   to   space 32768K,   0% used [0xfffffffbff000000, 
> 0xfffffffbff000000, 
> 0xfffffffc01000000)
>  concurrent mark-sweep generation total 14352384K, used 11676573K 
> [0xfffffffc03000000, 0xffffffff6f000000, 0xffffffff6f000000)
>  concurrent-mark-sweep perm gen total 98304K, used 67646K 
> [0xffffffff6f000000, 0xffffffff75000000, 0xffffffff75000000)
> 265150.611: [ParNew
> Desired survivor size 16777216 bytes, new threshold 2 (max 5)
> - age   1:   11435216 bytes,   11435216 total
> - age   2:    8139232 bytes,   19574448 total
> : 273751K->19272K(294912K), 0.2576767 secs] 
> 11950324K->11695845K(14647296K) Heap after GC invocations=57328:
> Heap
>  par new generation   total 294912K, used 19272K [0xfffffffbef000000, 
> 
> 0xfffffffc03000000, 0xfffffffc03000000)
>   eden space 262144K,   0% used [0xfffffffbef000000, 
> 0xfffffffbef000000, 
> 0xfffffffbff000000)
>   from space 32768K,  58% used [0xfffffffbff000000, 
> 0xfffffffc002d21b0, 
> 0xfffffffc01000000)
>   to   space 32768K,   0% used [0xfffffffc01000000, 
> 0xfffffffc01000000, 
> 0xfffffffc03000000)
>  concurrent mark-sweep generation total 14352384K, used 11676573K 
> [0xfffffffc03000000, 0xffffffff6f000000, 0xffffffff6f000000)
>  concurrent-mark-sweep perm gen total 98304K, used 67646K 
> [0xffffffff6f000000, 0xffffffff75000000, 0xffffffff75000000)
> } , 0.2600295 secs]
> 265152.992: [GC  {Heap before GC invocations=57328:
> Heap
>  par new generation   total 294912K, used 281416K [0xfffffffbef000000, 
> 
> 0xfffffffc03000000, 0xfffffffc03000000)
>   eden space 262144K, 100% used [0xfffffffbef000000, 
> 0xfffffffbff000000, 
> 0xfffffffbff000000)
>   from space 32768K,  58% used [0xfffffffbff000000, 
> 0xfffffffc002d21b0, 
> 0xfffffffc01000000)
>   to   space 32768K,   0% used [0xfffffffc01000000, 
> 0xfffffffc01000000, 
> 0xfffffffc03000000)
>  concurrent mark-sweep generation total 14352384K, used 11676573K 
> [0xfffffffc03000000, 0xffffffff6f000000, 0xffffffff6f000000)
>  concurrent-mark-sweep perm gen total 98304K, used 67646K 
> [0xffffffff6f000000, 0xffffffff75000000, 0xffffffff75000000)
> 265152.994: [ParNew (promotion failed)
> Desired survivor size 16777216 bytes, new threshold 2 (max 5)
> - age   1:   15741536 bytes,   15741536 total
> - age   2:    7459336 bytes,   23200872 total
> : 281416K->281416K(294912K), 2.7625640 secs]265155.757: 
> [CMS265176.917: 
> [CMS-concurrent-preclean: 30.615/36.559 secs]
>  (concurrent mode failure)[Unloading class 
> sun.reflect.GeneratedSerializationConstructorAccessor193]
> 
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use