Seeking assistance with long garbage collection pauses with G1GC

Tue Jan 14 13:34:01 PST 2014

Hello,

I wonder if there is anything the VM can do to avoid this? Maybe with some  
memadvice, changed allocation pattern or similiar? Is this only a problem  
when the VM does not use LargePages itself, or is it affected in that case  
as well?

Gruss
Bernd

Am 14.01.2014, 21:10 Uhr, schrieb Steven Toth <stoth at miami-holdings.com>:

> Charlie, thank you very much.  After disabling THP on our servers and  
> running for the past few weeks in production we've received no long  
> pauses for GC's.
>
> That was a lifesaver.
>
> -Steve
>
>
> -----Original Message-----
> From: charlie hunt [mailto:charlesjhunt at gmail.com]
> Sent: Thursday, December 12, 2013 11:51 AM
> To: Steven Toth
> Cc: hotspot-gc-use at openjdk.java.net; Randy Foster
> Subject: Re: Seeking assistance with long garbage collection pauses with  
> G1GC
>
> Fyi, G1 was not officially supported on until JDK 1.7.0_04, aka 7u4.
>
> Not only are there many improvements in 7u4 vs 7u3, but many  
> improvements since 7u4.  I'd recommend you work with 7u40 or 7u45.
>
> All the above said, copy times look incredibly high for a 3 gb Java  
> heap.  Depending on your version of RHEL, if transparent huge pages are  
> an available feature on your version RHEL, disable it.  You might be  
> seeing huge page coalescing which is contributing to your high sys time.  
> Alternatively you may be paging / swapping, or possibly having high  
> thread context switching.
>
> You might also need to throttle back the number GC threads.
>
> hths,
>
> charlie ...
>
> On Dec 10, 2013, at 6:16 PM, Steven Toth <stoth at miami-holdings.com>  
> wrote:
>
>> Hello,
>>
>> We've been struggling with long pauses with the G1GC garbage collector  
>> for several weeks now and was hoping to get some assistance.
>>
>> We have a Java app running in a standalone JVM on RHEL.  The app  
>> listens for data on one or more sockets, queues the data, and has  
>> scheduled threads pulling the data off the queue and persisting it. The  
>> data is wide, over 700 data elements per record, though all of the data  
>> elements are small Strings, Integers, or Longs.
>>
>> The app runs smoothly for periods of time, sometimes 30 minutes to an  
>> hour, but then we experience one or more long garbage collection  
>> pauses. The logs indicate the majority of the pause time is spent in  
>> the Object Copy time. The long pauses also have high sys time relative  
>> to the other shorter collections.
>>
>> Here are the JVM details:
>>
>> java version "1.7.0_03"
>> Java(TM) SE Runtime Environment (build 1.7.0_03-b04) Java HotSpot(TM)  
>> 64-Bit Server VM (build 22.1-b02, mixed mode)
>>
>> Here are the JVM options:
>>
>> -XX:MaxPermSize=256m -XX:PermSize=256m -Xms3G -Xmx3G -XX:+UseG1GC  
>> -XX:G1HeapRegionSize=32M -XX:-UseGCOverheadLimit \  
>> -Xloggc:logs/gc-STAT5-collector.log -XX:+PrintGCDetails  
>> -XX:+PrintGCDateStamps \ -XX:+PrintGCTimeStamps  
>> -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=8  
>> -XX:GCLogFileSize=10M -XX:+PrintGCApplicationStoppedTime \  
>> -XX:MaxNewSize=1G -XX:NewSize=1G \ -XX:+PrintGCApplicationStoppedTime  
>> -XX:+PrintTenuringDistribution -XX:+PrintAdaptiveSizePolicy
>>
>> After several iterations of experimenting with an assortment of options  
>> (including no options other than -Xms and -Xmx) the aforementioned  
>> options have given us the best performance with the fewest amount of  
>> long pauses.  However we're still experiencing several dozen garbage  
>> collections a day that range from 1-5 seconds.
>>
>> The process is taskset to 4 cores (all on the same socket), but is  
>> barely using 2 of them. All of the processes on this box are pinned to  
>> their own cores (with 0 and 1 unused). The machine has plenty of free  
>> memory (20+G) and top shows the process using 2.5G of RES memory.
>>
>> A day's worth of garbage collection logs are attached, but here is an  
>> example of the GC log output with high Object Copy and sys time.  There  
>> are numerous GC events comparable to the example below with near  
>> identical Eden/Survivors/Heap sizes that take well under 100 millis  
>> whereas this example took over 2 seconds.
>>
>> [Object Copy (ms): 2090.4 2224.0 2484.0 2160.1 1603.9 2071.2 887.8  
>> 1608.1 1992.0 2030.5 1692.5 1583.9 2140.3 1703.0 2174.0 1949.5 1941.1  
>> 2190.1 2153.3 1604.1 1930.8 1892.6 1651.9
>>
>> [Eden: 1017M(1017M)->0B(1016M) Survivors: 7168K->8192K Heap:  
>> 1062M(3072M)->47M(3072M)]
>>
>> [Times: user=2.24 sys=7.22, real=2.49 secs]
>>
>> Any help would be greatly appreciated.
>>
>> Thanks.
>>
>> -Steve
>>
>>
>> ****Confidentiality Note**** This e-mail may contain confidential and  
>> or privileged information and is solely for the use of the sender's  
>> intended recipient(s). Any review, dissemination, copying, printing or  
>> other use of this e-mail by any other persons or entities is  
>> prohibited. If you have received this e-mail in error, please contact  
>> the sender immediately by reply email and delete the material from any  
>> computer.
>> <gc-STAT5-collector.log.zip>_______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>
> ***Confidentiality Note*** This e-mail may contain confidential and or  
> privileged information and is solely for the use of the sender's  
> intended recipient(s). Any review, dissemination, copying, printing or  
> other use of this e-mail by any other persons or entities is prohibited.  
> If you have received this e-mail in error, please contact the sender  
> immediately by reply email and delete the material from any computer.
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-- 
http://bernd.eckenfels.net