Periodic long minor GC pauses

[Shane Cox]

Periodically, our Java app on Linux experiences a long Minor GC pause that
cannot be accounted for by the GC time in the log file.  Instead, the pause
is captured as "real" (wall clock) time and is observable in our application
logs.  An example is below.  The GC completed in 56ms, but the application
was paused for 2.45 seconds.

2011-04-26T12:50:41.722-0400: 2117.157: [GC 2117.157: [ParNew:
943439K->104832K(943744K), 0.0481790 secs] 4909998K->4086751K(25060992K),
0.0485110 secs] [Times: user=0.34 sys=0.03, real=0.04 secs]
2011-04-26T12:50:43.882-0400: 2119.317: [GC 2119.317: [ParNew:
942852K->104832K(943744K), 0.0738000 secs] 4924772K->4150899K(25060992K),
0.0740980 secs] [Times: user=0.45 sys=0.12, real=0.07 secs]
2011-04-26T12:50:45.251-0400: 2120.686: [GC 2123.075: [ParNew:
943744K->79296K(943744K), 0.0559560 secs] 4989811K->4187520K(25060992K),
0.0563970 secs] [Times: user=0.31 sys=0.09, *real=2.45 secs]*
2011-04-26T12:50:48.493-0400: 2123.928: [GC 2123.928: [ParNew:
918208K->81040K(943744K), 0.0396620 secs] 5026432K->4189265K(25060992K),
0.0400030 secs] [Times: user=0.32 sys=0.00, real=0.04 secs]
2011-04-26T12:50:51.010-0400: 2126.445: [GC 2126.445: [ParNew:
919952K->104832K(943744K), 0.0845070 secs] 5028177K->4268050K(25060992K),
0.0848300 secs] [Times: user=0.52 sys=0.11, real=0.09 secs]


Initially I suspected swapping, but according to the free command, 0 bytes
of swap are in use.
>free -m
             total       used       free     shared    buffers     cached
Mem:         32168      28118       4050          0        824      12652
-/+ buffers/cache:      14641      17527
Swap:         8191          0       8191


Next, I read about a problem relating to mprotect() on Linux that can be
worked around with -XX:+UseMember.  I tried that, but I still see the same
unexplainable pauses.


Any suggestions/ideas?  We've upgraded to the latest JDK, but no luck.

Thanks,
Shane


java version "1.6.0_25"
Java(TM) SE Runtime Environment (build 1.6.0_25-b06)
Java HotSpot(TM) 64-Bit Server VM (build 20.0-b11, mixed mode)


Linux 2.6.18-128.el5 #1 SMP Wed Jan 21 08:45:05 EST 2009 x86_64 x86_64
x86_64 GNU/Linux


-verbose:gc  -Xms24g -Xmx24g -Xmn1g -Xss256k -XX:PermSize=256m
-XX:MaxPermSize=256m -XX:+PrintTenuringDistribution -XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled -XX:CMSInitiatingOccupancyFraction=70
-XX:+CMSClassUnloadingEnabled -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -XX:+UseCompressedStrings
-XX:+UseMembar
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20110426/f9ba1dd4/attachment.html