unexplained CMS pauses

[Shane Cox]

Our application is reporting long pauses when a minor GC occurs during the
Concurrent Mark phase of CMS.  The output below is a specific example.  All
of the GC pauses are less than 30ms (initial mark, remark, minor GC).
However, our app reported a 300ms pause.

56750.934: [GC [1 CMS-initial-mark: 702464K(1402496K)] 719045K(1551616K),
0.0131859 secs]
56750.947: [CMS-concurrent-mark-start]
56752.133: [GC 56752.133: [ParNew: 144393K->12122K(149120K), 0.0237615 secs]
846857K->719330K(1551616K), 0.0239988 secs]
56752.162: [CMS-concurrent-mark: 1.188/1.215 secs]
56752.162: [CMS-concurrent-preclean-start]
56752.243: [CMS-concurrent-preclean: 0.070/0.081 secs]
56752.243: [CMS-concurrent-abortable-preclean-start]
56752.765: [CMS-concurrent-abortable-preclean: 0.143/0.522 secs]
56752.766: [GC[YG occupancy: 77423 K (149120 K)]56752.766: [Rescan
(parallel) , 0.0065730 secs]56752.773: [weak refs processing, 0.0001983
secs] [1 CMS-remark: 707208K(1402496K)] 784631K(1551616K), 0.0068908 secs]
56752.773: [CMS-concurrent-sweep-start]
56753.209: [CMS-concurrent-sweep: 0.436/0.436 secs]
56753.209: [CMS-concurrent-reset-start]
56753.219: [CMS-concurrent-reset: 0.010/0.010 secs]


We only observe this behavior when a minor GC occurs during the Concurrent
Mark (which is rare).  Our app has reported pauses up to 1.2 seconds ...
which is generally the time it takes to perform a Concurrent Mark.


Any insight/help that you could provide would be much appreciated.

Thanks
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20090928/9a644523/attachment.htm>