1.4.2 PrintFLSStatistics Output

[Y Srinivas Ramakrishna]

Hi Neeraj --

> We are using Java 1.4.2_17 (64-bit mode) to run long running server
> application on solaris using following java options
> 
> -server -d64 -XX:+HandlePromotionFailure
> -XX:CMSInitiatingOccupancyFraction=70 -XX:NewSize=256m -XX:MaxNewSize=2
> 56m -XX:SurvivorRatio=10 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC
> -XX:+PrintTenuringDistribution -XX:PrintCMSStatistics=1 -XX:+PrintGCDetails
> -XX:+Pri
> ntGCTimeStamps -XX:PrintFLSStatistics=1 -XX:+PrintHeapAtGC
> -XX:+PrintClassHistogram -XX:PermSize=96m -XX:MaxPermSize=96m
> -XX:MaxTenuringThreshold=5 -X
> ms6g -Xmx6g -Xss256k
> 
> In order to isolate a fragmentation issue, we started using
> -XX:PrintFLSStatistics option to see if the fragmentation is really taking
> place. However, the output looks quite confusing. I have following specific
> queries around this (please refer to the GC logs given below):
> 
> 1. As per GC stats, around 5 GB of memory is taken by the application 
> so
> there should be ~0.75 GB free in tenured generation but BinaryTreeDictionary
> statistics show only around 38 MB of memory in Free List Trees? Where 
> have
> the rest of 700 MB gone?

The free space in the old generation is kept mainly in two kinds of free lists.
Free blocks larger than some threshold (i think 1 KB, but am not sure without
checking the code) are kept in a binary tree indexed by size and printed as
part of the "BinaryTreeDictionary". Free blocks smaller than that threshold
are kept in an array of free lists indexed by size. Since most objects
created by Java programs are usually smaller than the 1 KB threshold, you
will usually find that most of the dynamic footprint in the old generation
is in the smnaller blocks.

> 
> 2. Going by these stats, the total free space is only 349438 words 
> (~2.8 MB)
> but still minor collections succeed (before eventually getting promotion
> failed error). Where does the free space to provide Young Generation
> Guarantee (~240 MB) come from?

See above; the majority of the churn is expected to be in the smaller
blocks, with the larger ones providing a buffer for volatility in the
demand for the smaller blocks (plus the occasional large object or two)
-- provided the free block demand estimation and coalescing is working
OK.

> 
> 3. Why there are two sets of BinaryTreeDictionary stats?

There is one set for each of the Old Generation and the Perm Generation,
both of which are marked by the CMS collector. (But perm generation
collection requires an additional flag or two.)

> 
> Any help will be greatly appreciated. Thanks in advance.

Hope that helps, and feel free to ask more questions, and/or study the
associated code in OpenJDK 7 (src/share/vm/gc_implementation/concurrentMarkSweep).

The option -XX:PrintFLSStatistics=2 produces (at much higher cost)
stats related to the smaller free blocks kept in the array(s) indexed by
size as well.

-- ramki

> 
> Neeraj
> 
> =======================================JVM GC
> Logs====================================================
> 
> 40330.741: [ParNewBefore GC:
> Before GC:
> 
> Desired survivor size 11173888 bytes, new threshold 2 (max 5)
> - age   1:    7549224 bytes,    7549224 total
> - age   2:    5868416 bytes,   13417640 total
> : 231488K->13203K(240320K), 0.4537259 secs]
> 5235545K->5023066K(6269632K)Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 349438
> Max   Chunk Size: 349438
> Number of Blocks: 1
> Av.  Block  Size: 349438
> Tree      Height: 1
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 4440679
> Max   Chunk Size: 4440679
> Number of Blocks: 1
> Av.  Block  Size: 4440679
> Tree      Height: 1
>  Heap after GC invocations=2396:
> Heap
>  par new generation   total 240320K, used 13203K [0xfffffffdefc00000,
> 0xfffffffdffc00000, 0xfffffffdffc00000)
>   eden space 218496K,   0% used [0xfffffffdefc00000, 0xfffffffdefc00000,
> 0xfffffffdfd160000)
>   from space 21824K,  60% used [0xfffffffdfd160000, 0xfffffffdfde44d50,
> 0xfffffffdfe6b0000)
>   to   space 21824K,   0% used [0xfffffffdfe6b0000, 0xfffffffdfe6b0000,
> 0xfffffffdffc00000)
>  concurrent mark-sweep generation total 6029312K, used 5009862K
> [0xfffffffdffc00000, 0xffffffff6fc00000, 0xffffffff6fc00000)
>  concurrent-mark-sweep perm gen total 98304K, used 63210K
> [0xffffffff6fc00000, 0xffffffff75c00000, 0xffffffff75c00000)
> } , 0.4557118 secs]
> After GC:
> After GC:
> 40344.958: [GC  {Heap before GC invocations=2396:
> Heap
>  par new generation   total 240320K, used 231699K [0xfffffffdefc00000,
> 0xfffffffdffc00000, 0xfffffffdffc00000)
>   eden space 218496K, 100% used [0xfffffffdefc00000, 0xfffffffdfd160000,
> 0xfffffffdfd160000)
>   from space 21824K,  60% used [0xfffffffdfd160000, 0xfffffffdfde44d50,
> 0xfffffffdfe6b0000)
>   to   space 21824K,   0% used [0xfffffffdfe6b0000, 0xfffffffdfe6b0000,
> 0xfffffffdffc00000)
>  concurrent mark-sweep generation total 6029312K, used 5008129K
> [0xfffffffdffc00000, 0xffffffff6fc00000, 0xffffffff6fc00000)
>  concurrent-mark-sweep perm gen total 98304K, used 63210K
> [0xffffffff6fc00000, 0xffffffff75c00000, 0xffffffff75c00000)
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 353702
> Max   Chunk Size: 349438
> Number of Blocks: 9
> Av.  Block  Size: 39300
> Tree      Height: 5
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 4440679
> Max   Chunk Size: 4440679
> Number of Blocks: 1
> Av.  Block  Size: 4440679
> Tree      Height: 1
> 40344.960: [ParNewBefore GC:
> Before GC:
>  (promotion failed)
> Desired survivor size 11173888 bytes, new threshold 2 (max 5)
> - age   1:    7604792 bytes,    7604792 total
> - age   2:    5978704 bytes,   13583496 total
> : 231699K->231699K(240320K), 1.2985705 secs]40346.259: [CMS40358.345:
> [CMS-concurrent-sweep: 25.860/27.699 secs]
>  (CMS-concurrent-sweep yielded 2 times)
>  (concurrent mode failure)[Unloading class
> sun.reflect.GeneratedSerializationConstructorAccessor93]
> [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor30]
> [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor55]
> _______________________________________________
> 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