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)

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

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