Analysing Java Garbage Collector

Application Phases: Initialization → Steady state → Summary (optional)
– Initialization: startup, lots of allocations
– Steady state: where application spends the most time, running the ‘core’ part of the application
– Summary: produce report of what has happen, might be computationally intensive and maybe has lots of allocation as well
Note: Typically, the steady state is the most important

Performance
Three important performance attributes are throughput, latency, footprint
– Throughput – the percentage of time not spent on GC
– Latencies – the time when an app appears unresponsive because of GC
– Footprint – memory size
Note: Not all three are always important
– Usually select two of the three
– But you need to know what is important for your application

GC Logging
Yes even in production
– Very important, not just for testing, minimal overhead

Correlate application-level with GC/JVM level events
– GC not always to blame for long pauses
– Capture time/context sensitive events that might not be able to reproduce under testing

Flags

– -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:<file>
– -XX:+PrintGCDateStamps (from JDK6u4)
– -XX:+PrintHeapAtGC

GC Logging Output – 1

-XX:+PrintGCTimeStamps -XX:+PrintGCDetails
27.199: [Full GC (System)
[PSYoungGen: 81K->0K(26304K)]
[PSOldGen: 7497K->7559K(32256K)] 7579K->7559K(58560K)
[PSPermGen: 12166K-&gt;12166K(16384K)], <i>0.0495600 secs</i>]
[Times: user=<i>0.05 </i>sys=0.00, real=<i>0.04 secs</i>]
28.503: [GC
[PSYoungGen: 869K-&gt;64K(26304K)] 8429K-&gt;7623K(58560K),
0.0008190 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]

GC Logging Output – 2

-XX:+PrintGCDateStamps -XX:+PrintGCDetails
2011-04-25T10:55:50.007+0800: 9.140:
[GC [PSYoungGen: 8024K-&gt;1530K(26304K)] 15470K-&gt;10427K(58560K),
0.0023450 secs]
[Times: user=0.00 sys=0.00, real=0.01 secs]
2011-04-25T10:55:50.009+0800: 9.143:
[Full GC (System) [PSYoungGen: 1530K-&gt;0K(26304K)]
[PSOldGen: 8896K-&gt;7135K(32256K)] 10427K-&gt;7135K(58560K)
[PSPermGen: 11640K-&gt;11631K(23808K)], 0.0778080 secs]
[Times: user=0.12 sys=0.00, real=0.07 secs]

GC Logging Output – 3

-XX:+PrintGCHeapAtGC -Xloggc:&lt;file&gt;
{<b>Heap before GC invocations=20 (full 8)</b>:
PSYoungGen total 14144K, used 2287K [0xa3b90000, 0xa4b50000, 0xb3790000)
eden space 12160K, 18% used [0xa3b90000,0xa3dcbe00,0xa4770000)
from space 1984K, 0% used [0xa4770000,0xa4770000,0xa4960000)
to space 1984K, 0% used [0xa4960000,0xa4960000,0xa4b50000)
PSOldGen total 32256K, used 7465K [0x84390000, 0x86310000, 0xa3b90000)
object space 32256K, 23% used [0x84390000,0x84ada710,0x86310000)
PSPermGen total 19968K, used 11994K [0x80390000, 0x81710000, 0x84390000)
object space 19968K, 60% used [0x80390000,0x80f46bb0,0x81710000)
45.215: [GC 9753K-&gt;7538K(46400K), 0.0006110 secs]

Heap after GC invocations=20 (full 8):

PSYoungGen total 14144K, used 72K [0xa3b90000, 0xa4b50000, 0xb3790000)
eden space 12160K, 0% used [0xa3b90000,0xa3b90000,0xa4770000)
from space 1984K, 3% used [0xa4960000,0xa49723b0,0xa4b50000)
to space 1984K, 0% used [0xa4770000,0xa4770000,0xa4960000)
PSOldGen total 32256K, used 7465K [0x84390000, 0x86310000, 0xa3b90000)
object space 32256K, 23% used [0x84390000,0x84ada710,0x86310000)
PSPermGen total 19968K, used 11994K [0x80390000, 0x81710000, 0x84390000)
object space 19968K, 60% used [0x80390000,0x80f46bb0,0x81710000)
}

Choice of JVM
32-bit
– -d32 (default)
– For heap size up to 2.5G/3G

64-bit with/without compressed references
– -d64, -XX:+UseCompressedOops
– For heap size up to 26G or unlimited

32-bit to 64-bit migration
– Higher heap size requirement (approx 20%)
– Throughput impact (up to 20%, without compressed refs)

Internals of Java Garbage Collector

GC Responsibilities
Garbage Detection: Garbage are objects that are no longer reachable
Garbage Reclamation:Make space available to the running program again

HotSpot VM Heap Layout

SS#1: Survivor Space 1
SS#2: Survivor Space 2

How HotSpot’s GC Works

Empirical Statistics
Most objects are very short lived
– 80 – 98% of all newly allocated objects die within a few million instructions
– 80 – 98% of all newly allocated objects die before another megabyte has been allocated

Assumptions
Weak generation hypothesis
– Most new objects die young
– Concentrate effort on managing the young generation
– Make allocate/manage/deallocate cycle fast and efficient
For older objects, manage as little as possible
Keep young and old objects separate
Use different GC algorithms for each generation
– Different requirements for each group

Object Allocation

Mawazo

Mostly technology with occasional sprinkling of other random thoughts

amintabar

Amir Amintabar's personal page

101 Books

Reading my way through Time Magazine's 100 Greatest Novels since 1923 (plus Ulysses)

Seek, Plunnge and more...

My words, my world...

ARRM Foundation

Do not wait for leaders; do it alone, person to person - Mother Teresa

Executive Management

An unexamined life is not worth living – Socrates

Diabolical or Smart

Nitwit, Blubber, Oddment, Tweak !!

javaproffesionals

A topnotch WordPress.com site

thehandwritinganalyst

Just another WordPress.com site

coding algorithms

"An approximate answer to the right problem is worth a good deal more than an exact answer to an approximate problem." -- John Tukey