jdk 1.4.2_17 promotion failure (fragmentation?)

[Y Srinivas Ramakrishna]

Hi Doug --  You are mostly right about the differnce regarding
promotion failure and the "full promotion guarantee" between 1.4.2
and 5.0. However, recently some of the 5.0 code to relax the full promotion
guarantee, kick off CMS collections "ergonomically" and dealing
with unexpected promotion failure was backported to 1.4.2 (can;t
recall which version). So the version 1.4.2_17 that Mike is running
does behave somewhat like 5.0 in that respect.

It also seems from the GC snippet that a scavenge was attempted
but bailed midway (or at least so it would seem from the fact that
the scavenge time reports at 2.76 seconds or so -- quite likely
because of the bail-out and recovery phase of a failed scavenge).

We'll have to look to see why the heap might have gotten so
excessively fragmented, based on the fuller, more detailed
logs that Mike has provided.

-- ramki

> It is likely to be due to fragmentation of tenured (a CMS GC does not
> compact tenured). Under the 1.4.2 the 'New Generation Guarantee'
> requires that when a scavenge occurs there is contiguous space available
> in tenured equal to the size of the New area (5.0 relaxes that to just
> being enough space available, not necessarily contiguous).
> 
> The fix is easy: you are half-way there with setting
> -XX:CMSInitiatingOccupancyFraction=70. However to tell the JVM to take
> notice of it you also need to add -XX:+UseCMSInitiatingOccupancyOnly,
> then CMS Collections will always kick in when tenured is approx 70%
> full. I would suspect that currently they don't until tenured is well
> above 90% full (1.4.2 is more optimistic I think than 5.0 about its
> ability to schedule a CMS GC 'JIT with a bit to spare', but
> conc-mode-failures can still be a problem under 5.0).
> 
> Doug.
>  
> 
> -----Original Message-----
> From: hotspot-gc-use-bounces at openjdk.java.net
> [mailto:hotspot-gc-use-bounces at openjdk.java.net] On Behalf Of Mike Finn
> Sent: Tuesday, 12 August 2008 6:48 a.m.
> To: hotspot-gc-use at openjdk.java.net
> Subject: jdk 1.4.2_17 promotion failure (fragmentation?)
> 
> 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
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use