hotspot-gc-dev
Threads by month
- ----- 2026 -----
- March
- February
- January
- ----- 2025 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2024 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2023 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2022 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2021 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2020 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2019 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2018 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2017 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2016 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2015 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2014 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2013 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2012 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2011 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2010 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2009 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2008 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2007 -----
- December
- November
- October
- September
- August
- July
- June
- May
March 2009
- 10 participants
- 51 discussions
I think you are seeing variations in the survivor spaces
in the young gen. If the two survivors are of different
sizes (they are adjusted by GC ergonomics) you see something
like this. Actually the survivor spaces also grow and
shrink so will cause changes). Turn off the GC ergonomics
(-XX:-UseAdaptiveSizePolicy). That will fix the sizes to
the initial sizes.
On 03/11/09 12:37, Peng Du wrote:
> Hello, guys
>
> I am doing some analysis on the parallel GC for the old generation. But
> I am confused by the output of -XX:+PrintGCDetails. I intentionally set
> the size of the heap to be [-Xms8m -Xmx8m]. However, the GC log
> indicated that the size of heap was varying in between every GC (minor
> and full).
>
> For example:
> ===============================================================================================
> [GC [PSYoungGen: 768K->128K(896K)] 768K->320K(8064K), 0.0075060 secs]
> [Times: user=0.01 sys=0.01, real=0.01 secs]
> [GC [PSYoungGen: 876K->128K(896K)] 1069K->406K(8064K), 0.0060870 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 896K->128K(896K)] 1174K->507K(8064K), 0.0058220 secs]
> [Times: user=0.01 sys=0.00, real=0.01 secs]
> [GC [PSYoungGen: 896K->128K(512K)] 1390K->699K(7680K), 0.0019780 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 512K->64K(704K)] 1083K->727K(7872K), 0.0012320 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 445K->154K(704K)] 1109K->838K(7872K), 0.0017830 secs]
> [Times: user=0.00 sys=0.00, real=0.01 secs]
> [GC [PSYoungGen: 538K->144K(704K)] 1222K->848K(7872K), 0.0019050 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 416K->32K(704K)] 1262K->882K(7872K), 0.0025930 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 416K->32K(704K)] 1282K->906K(7872K), 0.0025650 secs]
> [Times: user=0.00 sys=0.00, real=0.01 secs]
> [GC [PSYoungGen: 416K->176K(704K)] 1290K->1058K(7872K), 0.0022590 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 560K->176K(704K)] 1442K->1098K(7872K), 0.0029060 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC [PSYoungGen: 560K->64K(704K)] 1482K->1142K(7872K), 0.0014460 secs]
> [Times: user=0.00 sys=0.00, real=0.00 secs]
> .......................
> ===============================================================================================
>
> My analysis requires the heap size to be fixed as well as the relative
> ratio of each generation within the heap. Is there a way I can strictly
> restrict the sizes of the heap and each generation?
>
> Thanks!
>
>
>
> Peng Du
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use(a)openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use(a)openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
2
1
With CMS use 2 ParallelGCThreads
Also pay attention to the young gen size, survivor space sizes
and tenuring threshold. In jdk6 the defaults were changed
to be more a little more generally applicable (as opposed
to too pause time focused). Look at
http://java.sun.com/javase/6/docs/technotes/guides/vm/cms-6.html
for the changes. You might want to have an even larger
young gen. There's some rational for the changes here
http://blogs.sun.com/jonthecollector/entry/the_fault_with_defaults
Good luck.
On 03/10/09 10:45, Alex Aisinzon wrote:
> Jon
>
> I will plan more tests with CMS: on a 2 core server with Sun JDK 1.5,
> how many GC threads will/should be used by CMS: 1 or 2. I am asking
> because I wonder if it makes sense to force the number of GC threads to
> 2 or not.
> I did force that number for UseParallelGC and UseParallelOldGC but CMS
> likely works differently.
>
> Thanks again
>
> Regards
>
> Alex A
>
> -----Original Message-----
> From: Jon.Masamitsu(a)Sun.COM [mailto:Jon.Masamitsu@Sun.COM]
> Sent: Tuesday, March 10, 2009 10:36 AM
> To: Alex Aisinzon
> Cc: hotspot-gc-use(a)openjdk.java.net
> Subject: Re: Scalability issues with ParallelOld
>
>
>
> On 03/10/09 09:36, Alex Aisinzon wrote:
>> Jon
>>
>> As always, your feedback is always enlightening and very much
>> appreciated.
>> I have some additional comments/questions before closing that
>> conversation thread:
>> The server has 2 cores. We have servers with more cores (4 and 8) and
>> will likely run some tests with those. On these servers, ParallelOldGC
>> may or may not prove better performing for the following reason: while
> I
>> used a single JVM on that 2 cores server, we would use 4 JVMs on an 8
>> core server (same ratio of one JVM for 2 cores). In that case, the
> many
>> threads used during a full GC would compete for resources with the
> other
>> running JVMs.
>
> Yes, multiple VM's doing GC's at the same time will
> compete for resources. That's not just true for UseParallelOldGC.
> It's also the case with UseParallelGC where parallel GC threads
> are used for the young gen collection. Consider setting
> ParallelGCThreads explicitly if you frequent instances of poor
> scaling (i.e., if you look at the user time and the real time
> and they show little scaling).
>
>> Some Sun benchmarks (by example
>>
> http://www.spec.org/jbb2005/results/res2008q2/jbb2005-20080506-00485.htm
>> l) infer that ParallelOldGC may be beneficial even with 2 cores. My
>> hypothesis is that this is because the application tested (the
>> SPECJBB2005 code) uses much fewer longer lived objects, as shown by
> the
>> JVM tunings (-Xmx3350m -Xms3350m -Xmn2800m infers that the tenured is
>> only 550MB large).
>
> That benchmark benefits from the young generation parallel GC
> (UseParallelGC) which scales better than the old generation
> parallel GC. Also, as you note, much of the data is short
> lived so gets collected by the young generation collections.
>
>> Thanks again for your thoughts.
>
> If you do anymore CMS experiments, send me a log and
> I'll look to see if it is worth pursuing.
>
>
>> Regards
>>
>> Alex Aisinzon
>>
>> -----Original Message-----
>> From: Jon.Masamitsu(a)Sun.COM [mailto:Jon.Masamitsu@Sun.COM]
>> Sent: Tuesday, March 10, 2009 8:57 AM
>> To: Alex Aisinzon
>> Cc: hotspot-gc-use(a)openjdk.java.net
>> Subject: Re: Scalability issues with ParallelOld
>>
>>
>>
>> On 03/09/09 16:14, Alex Aisinzon wrote:
>>> Hi all
>>>
>>> I try to am experimenting with ParallelOldGC in our performance
>> testing
>>> environment.
>>> The server is a Dual Core Opteron 280 (old hardware with few cores by
>>> today's standard).
>>> With Sun JDK 1.5, full collections with ParallelGC and 2 GC threads
>> last
>>> between 5 & 7 seconds. I tried used ParallelOld with 2 GC threads.
> The
>>> full collections are almost twice the time.
>>> I then tried with Sun JDK 1.6 to see if it was any better. It is not
>>> significantly
>> In the logs with UseParallelOldGC I see an average major pause of
> about
>> 14 sec with 1.5 and about 9.3 sec with 1.6. That's about the
>> improvement I would expect.
>>
>> With UseParallelOldGC using 2 GC threads is about the break even
> point.
>> That depends on the application. I would not expect using 2 GC
> threads
>> with UseParallelOldGC to be better than UseParallelGC.
> UseParallelOldGC
>> does do more work. If you look at the last entry in the 1.6 log
>>
>> 3034.907: [Full GC [PSYoungGen: 12157K->0K(276160K)] [ParOldGen:
>> 2324556K->828465K(2330176K)] 2336714K->828465K(2606336K) [PSPermGen:
>> 82577K->82549K(102400K)], 9.0664330 secs] [Times: user=16.81 sys=0.03,
>
>> real=9.07 secs]
>>
>> the user time is 16.81 secs and the real time is 9 secs so that says
> to
>> me that we have both GC threads working in parallel and perhaps doing
>> twice the work of the UseParallelGC on a full collection.
>>
>>
>>> I have enclosed the logs (Sun JDK 1.5 with ParallelGC and
>> ParallelOldGC
>>> and Sun JDK 1.6 with ParallelOldGC).
>>>
>>> I have also experimented with CMS with mixed results: I could not get
>> it
>>> to work when using the 64 bit release and double the heap. With 32
>> bit,
>>> it experienced some rare but longer pauses than ParallelGC.
> Therefore,
>>> it did not seem a good alternative to ParallelGC to consistently have
>>> short pauses.
>> CMS sometimes takes quite a bit of tuning to run well. The goal of
>> CMS is to not have the full GC's (that would be analogous to the full
>> GC's with UseParallelGC or UseParallelOldGC).
>>
>>> One thing to note is that our application has a large amount of long
>>> lived objects. My experience is that a lot of long lived objects make
>>> full collections longer.
>> This (plus the need for low pauses) would indicate that CMS may a good
>> choice although CMS works best when there is excess processing power
>> that CMS can use concurrently with the application. Does you
>> platform have 2 or 4 hardware threads?
>>
>>> What are my options to consistently reduce the longest GC pauses?
>>>
>>> Would our application profile (lots of long lived objects) make it a
>>> good candidate for the coming lower collector aka G1?
>> Depends of lots of things but part of the design of G1 is
>> is to do collections of the heap in increments. You would
>> get shorter pauses that a full GC certainly but would get
>> more collections (more, shorter collections). G1 also does works
>> concurrently with application so having available processing
>> power helps.
>>
>>
>>> Thanks in advance
>>>
>>> Alex Aisinzon
>>>
>>> -----Original Message-----
>>> From: hotspot-gc-use-bounces(a)openjdk.java.net
>>> [mailto:hotspot-gc-use-bounces@openjdk.java.net] On Behalf Of
>>> hotspot-gc-use-request(a)openjdk.java.net
>>> Sent: Wednesday, February 25, 2009 8:41 PM
>>> To: hotspot-gc-use(a)openjdk.java.net
>>> Subject: hotspot-gc-use Digest, Vol 15, Issue 7
>>>
>>> Send hotspot-gc-use mailing list submissions to
>>> hotspot-gc-use(a)openjdk.java.net
>>>
>>> To subscribe or unsubscribe via the World Wide Web, visit
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>> or, via email, send a message with subject or body 'help' to
>>> hotspot-gc-use-request(a)openjdk.java.net
>>>
>>> You can reach the person managing the list at
>>> hotspot-gc-use-owner(a)openjdk.java.net
>>>
>>> When replying, please edit your Subject line so it is more specific
>>> than "Re: Contents of hotspot-gc-use digest..."
>>>
>>>
>>> Today's Topics:
>>>
>>> 1. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application (Jon
>> Masamitsu)
>>> 2. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application (Y Srinivas
>>> Ramakrishna)
>>>
>>>
>>>
> ----------------------------------------------------------------------
>>> Message: 1
>>> Date: Wed, 25 Feb 2009 14:42:32 -0800
>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>,
>>> hotspot-gc-use(a)openjdk.java.net
>>> Message-ID: <49A5C958.8070704(a)sun.com>
>>> Content-Type: text/plain; charset=us-ascii
>>>
>>> David,
>>>
>>> This is an educated guess but I would say that no out-of-memory
>>> was thrown because there was still significant space in the
>>> young gen after a collection.
>>>
>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)] [PSOldGen:
>>> 683678K->683678K(699072K)] 781918K->781918K(913792K) [PSPermGen:
>>>
>>> The young gen capacity being 214720K and the used space
>>> in the young gen being 98240K. That missing space may be in the
>>> survivor spaces which are not directly available to the
>>> application with the UseParallelGC collector. The logic
>>> that would throw the out-of-memory is very conservative
>>> and probably does not allow for such a case.
>>>
>>> Jon
>>>
>>>
>>>
>>> David Sitsky wrote On 02/25/09 13:59,:
>>>
>>>> Hi Ramki,
>>>>
>>>> The next message I posted to the hotspot list showed a GC trace when
>> I
>>>> allocated more memory (an extra 300 megs), where everything worked
>>> fine.
>>>> I am well aware that the heap size for this particular application
>>> and
>>>> data set was too small. My run from last night with the extra heap
>> is
>>>> still running nicely.
>>>>
>>>> I reported this issue, because it seemed to me no progress was being
>
>>>> made and no OutOfMemoryErrors were being generated. The application
>>> was
>>>> effectively "stuck" making no progress at all. I couldn't even
>> connect
>>>> to it with jconsole, although jstack worked fine.
>>>>
>>>> My understanding is this condition is meant to be detected, and
>>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>>> This
>>>> is with the parallel GC.
>>>>
>>>> Cheers,
>>>> David
>>>>
>>>> Y Srinivas Ramakrishna wrote:
>>>>
>>>>
>>>>> Doesn't the heap look too full?
>>>>> If a 64-bit JVM why use such an oversubscribed
>>>>> and small heap? Either make the old gen bigger or make the
>>>>> young gen smaller (giving that space to the older gen)
>>>>> so that each scavenge does not degenerate to a full gc
>>>>> as in your trace below.
>>>>>
>>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>>> so i have cross-posted over to that list with a bcc to
>>>>> the hotspot-dev list.
>>>>>
>>>>> Also the GC tuning guides to be found here might be useful
>>>>> reading:-
>>>>>
>>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>>
>>>>> -- ramki
>>>>>
>>>>> ----- Original Message -----
>>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>>>> To: David Sitsky <sits(a)nuix.com>
>>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>>> <Thomas.Rodriguez(a)Sun.COM>
>>>>>
>>>>>
>>>>>> David,
>>>>>>
>>>>>> Can you also send a GC log from a run where there
>>>>>> is not a problem? As I understand it, that would
>>>>>> be a 32bit run.
>>>>>>
>>>>>> Jon
>>>>>>
>>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>>
>>>>>>
>>>>>>
>>>>>>> Jon Masamitsu wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> ...
>>>>>>>>>
>>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>>
>>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>>>>>
>>>>>>>>>
>>>>>> gathering the
>>>>>>
>>>>>>
>>>>>>>>> GC logs.
>>>>>>>>> If you've already gathering some, send those but in future
> runs,
>>>>>>>>>
>>>>>>>>>
>>>>>> use the
>>>>>>
>>>>>>
>>>>>>>>> above.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>> Here is a sample of output from a stuck process. You can see its
>
>>>>>>>
>>>>>>>
>>>>>> doing
>>>>>>
>>>>>>
>>>>>>> a full GC about every 3 seconds, and it seems as if there is
>> little
>>>>>>> progress..
>>>>>>>
>>>>>>> Please let me know if you need more information.
>>>>>>>
>>>>>>> Cheers,
>>>>>>> David
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>> _______________________________________________
>>>> hotspot-gc-use mailing list
>>>> hotspot-gc-use(a)openjdk.java.net
>>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>>
>>>>
>>>
>>> ------------------------------
>>>
>>> Message: 2
>>> Date: Wed, 25 Feb 2009 20:41:10 -0800
>>> From: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: hotspot-gc-use(a)openjdk.java.net
>>> Message-ID: <71e0b0454a6.49a5ace6(a)sun.com>
>>> Content-Type: text/plain; charset=us-ascii
>>>
>>>
>>> Yes, sorry, my bad.
>>> I think Jon can explain that the trace you included
>>> will show metrics (GC overhead and Space free(d)) that somehow
>>> fall below the thresholds that trigger the GCOverhead related
>>> OOM. These thresholds can of course be modified via suitable
>>> JVM options.
>>>
>>> -- ramki
>>>
>>> ----- Original Message -----
>>> From: David Sitsky <sits(a)nuix.com>
>>> Date: Wednesday, February 25, 2009 1:59 pm
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>>> Cc: hotspot-gc-use(a)openjdk.java.net
>>>
>>>
>>>> Hi Ramki,
>>>>
>>>> The next message I posted to the hotspot list showed a GC trace when
>> I
>>>> allocated more memory (an extra 300 megs), where everything worked
>>>> fine. I am well aware that the heap size for this particular
>>>> application and data set was too small. My run from last night with
>
>>>> the extra heap is still running nicely.
>>>>
>>>> I reported this issue, because it seemed to me no progress was being
>
>>>> made and no OutOfMemoryErrors were being generated. The application
>
>>>> was effectively "stuck" making no progress at all. I couldn't even
>>>> connect to it with jconsole, although jstack worked fine.
>>>>
>>>> My understanding is this condition is meant to be detected, and
>>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>>>> This is with the parallel GC.
>>>>
>>>> Cheers,
>>>> David
>>>>
>>>> Y Srinivas Ramakrishna wrote:
>>>>> Doesn't the heap look too full?
>>>>> If a 64-bit JVM why use such an oversubscribed
>>>>> and small heap? Either make the old gen bigger or make the
>>>>> young gen smaller (giving that space to the older gen)
>>>>> so that each scavenge does not degenerate to a full gc
>>>>> as in your trace below.
>>>>>
>>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>>> so i have cross-posted over to that list with a bcc to
>>>>> the hotspot-dev list.
>>>>>
>>>>> Also the GC tuning guides to be found here might be useful
>>>>> reading:-
>>>>>
>>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>>
>>>>> -- ramki
>>>>>
>>>>> ----- Original Message -----
>>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>
>>>> platform within data processing application
>>>>> To: David Sitsky <sits(a)nuix.com>
>>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>>> <Thomas.Rodriguez(a)Sun.COM>
>>>>>> David,
>>>>>>
>>>>>> Can you also send a GC log from a run where there
>>>>>> is not a problem? As I understand it, that would
>>>>>> be a 32bit run.
>>>>>>
>>>>>> Jon
>>>>>>
>>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>>
>>>>>>> Jon Masamitsu wrote:
>>>>>>>
>>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>>
>>>>>>>>
>>>>>>>>> ...
>>>>>>>>>
>>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>>
>>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>> gathering the
>>>>>>>>> GC logs.
>>>>>>>>> If you've already gathering some, send those but in future
> runs,
>>>>>> use the
>>>>>>>>> above.
>>>>>>>>>
>>>>>>> Here is a sample of output from a stuck process. You can see its
>
>>>>>> doing
>>>>>>> a full GC about every 3 seconds, and it seems as if there is
>> little
>>>> progress..
>>>>>>> Please let me know if you need more information.
>>>>>>>
>>>>>>> Cheers,
>>>>>>> David
>>>>>>>
>>>>>>> 62402.320: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8063178 secs] [Times:
>> user=2.81
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62405.128: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8029997 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62407.932: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7917325 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62410.725: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891387 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62413.515: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7649110 secs] [Times:
>> user=2.76
>>>> sys=0.00, real=2.76 secs]
>>>>>>> 62416.281: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7803983 secs] [Times:
>> user=2.78
>>>> sys=0.00, real=2.78 secs]
>>>>>>> 62419.063: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7643979 secs] [Times:
>> user=2.76
>>>> sys=0.00, real=2.76 secs]
>>>>>>> 62421.828: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8114336 secs] [Times:
>> user=2.81
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62424.640: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7964912 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62427.438: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8107278 secs] [Times:
>> user=2.81
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62430.249: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.2345212 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=3.24 secs]
>>>>>>> 62433.484: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8341520 secs] [Times:
>> user=2.82
>>>> sys=0.00, real=2.82 secs]
>>>>>>> 62436.319: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8698768 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62439.190: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9323230 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62442.124: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9644960 secs] [Times:
>> user=2.96
>>>> sys=0.00, real=2.96 secs]
>>>>>>> 62445.089: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.0059221 secs] [Times:
>> user=3.00
>>>> sys=0.00, real=3.00 secs]
>>>>>>> 62448.095: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9832815 secs] [Times:
>> user=3.00
>>>> sys=0.00, real=2.99 secs]
>>>>>>> 62451.079: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9587156 secs] [Times:
>> user=2.93
>>>> sys=0.00, real=2.95 secs]
>>>>>>> 62454.039: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9488345 secs] [Times:
>> user=2.92
>>>> sys=0.00, real=2.95 secs]
>>>>>>> 62456.988: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8969788 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62459.886: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8794991 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62462.766: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8842411 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62465.651: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683675K(699072K)] 781916K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8669173 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.85 secs]
>>>>>>> 62468.519: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8664429 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62471.386: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8844494 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62474.271: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8648398 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62477.137: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8971068 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62480.034: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8655618 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62482.901: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.0366140 secs] [Times:
>> user=2.78
>>>> sys=0.00, real=3.04 secs]
>>>>>>> 62485.939: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8541753 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.85 secs]
>>>>>>> 62488.794: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8582816 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62491.653: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8673218 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62494.521: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9014120 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62497.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805843 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62500.305: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8905128 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62503.196: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052007 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62506.102: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9004575 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62509.003: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9160655 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62511.920: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9013277 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62514.822: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982061 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62517.721: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8922437 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62520.614: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8873520 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62523.502: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805296 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62526.383: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8958714 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62529.279: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8735384 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62532.154: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8705676 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62535.025: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8723947 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62537.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8624400 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62540.761: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8245748 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62543.587: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8432269 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62546.432: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8394157 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62549.272: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8471951 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.85 secs]
>>>>>>> 62552.121: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8584107 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62554.981: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8376807 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62557.820: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8402486 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62560.661: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8482704 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.85 secs]
>>>>>>> 62563.511: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8115973 secs] [Times:
>> user=2.81
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62566.324: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8523278 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62569.177: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8128563 secs] [Times:
>> user=2.81
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62571.990: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7830644 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62574.774: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8065106 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62577.582: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892171 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62580.372: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8059306 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62583.179: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8641470 secs] [Times:
>> user=2.82
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62586.044: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8421364 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62588.887: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8852699 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62591.773: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9164279 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62594.690: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9450010 secs] [Times:
>> user=2.95
>>>> sys=0.00, real=2.95 secs]
>>>>>>> 62597.636: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9744636 secs] [Times:
>> user=2.98
>>>> sys=0.00, real=2.98 secs]
>>>>>>> 62600.611: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9900849 secs] [Times:
>> user=2.99
>>>> sys=0.00, real=3.00 secs]
>>>>>>> 62603.602: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.6332370 secs] [Times:
>> user=2.62
>>>> sys=0.00, real=2.62 secs]
>>>>>>> 62606.236: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9801260 secs] [Times:
>> user=2.95
>>>> sys=0.00, real=2.98 secs]
>>>>>>> 62609.226: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9166374 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62612.150: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9475729 secs] [Times:
>> user=2.95
>>>> sys=0.00, real=2.95 secs]
>>>>>>> 62615.098: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9328670 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.93 secs]
>>>>>>> 62618.040: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8963825 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62620.937: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8834715 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62623.821: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8800691 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62626.701: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683677K(699072K)] 781918K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8642587 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62629.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8574615 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62632.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8383412 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62635.264: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8409891 secs] [Times:
>> user=2.82
>>>> sys=0.00, real=2.84 secs]
>>>>>>> 62638.106: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7906216 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62640.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891730 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62643.688: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892940 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62646.479: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7766807 secs] [Times:
>> user=2.78
>>>> sys=0.00, real=2.78 secs]
>>>>>>> 62649.257: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7796531 secs] [Times:
>> user=2.78
>>>> sys=0.00, real=2.78 secs]
>>>>>>> 62652.037: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7687240 secs] [Times:
>> user=2.76
>>>> sys=0.00, real=2.76 secs]
>>>>>>> 62654.807: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7613769 secs] [Times:
>> user=2.76
>>>> sys=0.00, real=2.76 secs]
>>>>>>> 62657.570: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7712254 secs] [Times:
>> user=2.78
>>>> sys=0.00, real=2.78 secs]
>>>>>>> 62660.342: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7968108 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62663.139: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7924173 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.79 secs]
>>>>>>> 62665.933: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8002912 secs] [Times:
>> user=2.79
>>>> sys=0.00, real=2.81 secs]
>>>>>>> 62668.736: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8291434 secs] [Times:
>> user=2.82
>>>> sys=0.00, real=2.82 secs]
>>>>>>> 62671.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8527186 secs] [Times:
>> user=2.86
>>>> sys=0.00, real=2.85 secs]
>>>>>>> 62674.419: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982825 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62677.318: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9254483 secs] [Times:
>> user=2.93
>>>> sys=0.00, real=2.93 secs]
>>>>>>> 62680.244: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9707015 secs] [Times:
>> user=2.95
>>>> sys=0.00, real=2.96 secs]
>>>>>>> 62683.216: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9894145 secs] [Times:
>> user=3.00
>>>> sys=0.00, real=3.00 secs]
>>>>>>> 62686.206: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9870305 secs] [Times:
>> user=2.98
>>>> sys=0.00, real=2.98 secs]
>>>>>>> 62689.193: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9884647 secs] [Times:
>> user=2.98
>>>> sys=0.00, real=3.00 secs]
>>>>>>> 62692.183: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9635276 secs] [Times:
>> user=2.96
>>>> sys=0.00, real=2.96 secs]
>>>>>>> 62695.147: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9407559 secs] [Times:
>> user=2.93
>>>> sys=0.00, real=2.93 secs]
>>>>>>> 62698.088: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9299386 secs] [Times:
>> user=2.93
>>>> sys=0.00, real=2.93 secs]
>>>>>>> 62701.019: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8994903 secs] [Times:
>> user=2.90
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62703.919: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9163417 secs] [Times:
>> user=2.92
>>>> sys=0.00, real=2.92 secs]
>>>>>>> 62706.836: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9216473 secs] [Times:
>> user=2.93
>>>> sys=0.00, real=2.93 secs]
>>>>>>> 62709.758: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052547 secs] [Times:
>> user=2.89
>>>> sys=0.00, real=2.90 secs]
>>>>>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8902824 secs] [Times:
>> user=2.85
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62715.555: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8865932 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.89 secs]
>>>>>>> 62718.442: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8605445 secs] [Times:
>> user=2.87
>>>> sys=0.00, real=2.87 secs]
>>>>>>> 62721.304: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8662771 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.86 secs]
>>>>>>> 62724.171: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>> [PSOldGen: 683679K->683679K(699072K)] 781919K->781919K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8369076 secs] [Times:
>> user=2.84
>>>> sys=0.00, real=2.84 secs]
>>> ------------------------------
>>>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use(a)openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>
>>>
>>> End of hotspot-gc-use Digest, Vol 15, Issue 7
>>> *********************************************
>>>
>>>
>>>
> ------------------------------------------------------------------------
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use(a)openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use(a)openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
1
0
Alex Aisinzon wrote:
> Jon
>
> I will plan more tests with CMS: on a 2 core server with Sun JDK 1.5,
> how many GC threads will/should be used by CMS: 1 or 2. I am asking
> because I wonder if it makes sense to force the number of GC threads to
> 2 or not.
>
When using CMS on a 2-core box, the parallel scavenge and CMS' parallel
remark
phases will pick 2 worker threads by default.
Depending on available cpu and throughput you might gain from iCMS on a
2-core box
to reduce (smooth out) the impact on the application when CMS runs.
> I did force that number for UseParallelGC and UseParallelOldGC but CMS
> likely works differently.
>
Yes, ParallelGCThreads also works for CMS/ParNew.
-- ramki
> Thanks again
>
> Regards
>
> Alex A
>
> -----Original Message-----
> From: Jon.Masamitsu(a)Sun.COM [mailto:Jon.Masamitsu@Sun.COM]
> Sent: Tuesday, March 10, 2009 10:36 AM
> To: Alex Aisinzon
> Cc: hotspot-gc-use(a)openjdk.java.net
> Subject: Re: Scalability issues with ParallelOld
>
>
>
> On 03/10/09 09:36, Alex Aisinzon wrote:
>
>> Jon
>>
>> As always, your feedback is always enlightening and very much
>> appreciated.
>> I have some additional comments/questions before closing that
>> conversation thread:
>> The server has 2 cores. We have servers with more cores (4 and 8) and
>> will likely run some tests with those. On these servers, ParallelOldGC
>> may or may not prove better performing for the following reason: while
>>
> I
>
>> used a single JVM on that 2 cores server, we would use 4 JVMs on an 8
>> core server (same ratio of one JVM for 2 cores). In that case, the
>>
> many
>
>> threads used during a full GC would compete for resources with the
>>
> other
>
>> running JVMs.
>>
>
> Yes, multiple VM's doing GC's at the same time will
> compete for resources. That's not just true for UseParallelOldGC.
> It's also the case with UseParallelGC where parallel GC threads
> are used for the young gen collection. Consider setting
> ParallelGCThreads explicitly if you frequent instances of poor
> scaling (i.e., if you look at the user time and the real time
> and they show little scaling).
>
>
>> Some Sun benchmarks (by example
>>
>>
> http://www.spec.org/jbb2005/results/res2008q2/jbb2005-20080506-00485.htm
>
>> l) infer that ParallelOldGC may be beneficial even with 2 cores. My
>> hypothesis is that this is because the application tested (the
>> SPECJBB2005 code) uses much fewer longer lived objects, as shown by
>>
> the
>
>> JVM tunings (-Xmx3350m -Xms3350m -Xmn2800m infers that the tenured is
>> only 550MB large).
>>
>
> That benchmark benefits from the young generation parallel GC
> (UseParallelGC) which scales better than the old generation
> parallel GC. Also, as you note, much of the data is short
> lived so gets collected by the young generation collections.
>
>
>> Thanks again for your thoughts.
>>
>
> If you do anymore CMS experiments, send me a log and
> I'll look to see if it is worth pursuing.
>
>
>
>> Regards
>>
>> Alex Aisinzon
>>
>> -----Original Message-----
>> From: Jon.Masamitsu(a)Sun.COM [mailto:Jon.Masamitsu@Sun.COM]
>> Sent: Tuesday, March 10, 2009 8:57 AM
>> To: Alex Aisinzon
>> Cc: hotspot-gc-use(a)openjdk.java.net
>> Subject: Re: Scalability issues with ParallelOld
>>
>>
>>
>> On 03/09/09 16:14, Alex Aisinzon wrote:
>>
>>> Hi all
>>>
>>> I try to am experimenting with ParallelOldGC in our performance
>>>
>> testing
>>
>>> environment.
>>> The server is a Dual Core Opteron 280 (old hardware with few cores by
>>> today's standard).
>>> With Sun JDK 1.5, full collections with ParallelGC and 2 GC threads
>>>
>> last
>>
>>> between 5 & 7 seconds. I tried used ParallelOld with 2 GC threads.
>>>
> The
>
>>> full collections are almost twice the time.
>>> I then tried with Sun JDK 1.6 to see if it was any better. It is not
>>> significantly
>>>
>> In the logs with UseParallelOldGC I see an average major pause of
>>
> about
>
>> 14 sec with 1.5 and about 9.3 sec with 1.6. That's about the
>> improvement I would expect.
>>
>> With UseParallelOldGC using 2 GC threads is about the break even
>>
> point.
>
>> That depends on the application. I would not expect using 2 GC
>>
> threads
>
>> with UseParallelOldGC to be better than UseParallelGC.
>>
> UseParallelOldGC
>
>> does do more work. If you look at the last entry in the 1.6 log
>>
>> 3034.907: [Full GC [PSYoungGen: 12157K->0K(276160K)] [ParOldGen:
>> 2324556K->828465K(2330176K)] 2336714K->828465K(2606336K) [PSPermGen:
>> 82577K->82549K(102400K)], 9.0664330 secs] [Times: user=16.81 sys=0.03,
>>
>
>
>> real=9.07 secs]
>>
>> the user time is 16.81 secs and the real time is 9 secs so that says
>>
> to
>
>> me that we have both GC threads working in parallel and perhaps doing
>> twice the work of the UseParallelGC on a full collection.
>>
>>
>>
>>> I have enclosed the logs (Sun JDK 1.5 with ParallelGC and
>>>
>> ParallelOldGC
>>
>>> and Sun JDK 1.6 with ParallelOldGC).
>>>
>>> I have also experimented with CMS with mixed results: I could not get
>>>
>> it
>>
>>> to work when using the 64 bit release and double the heap. With 32
>>>
>> bit,
>>
>>> it experienced some rare but longer pauses than ParallelGC.
>>>
> Therefore,
>
>>> it did not seem a good alternative to ParallelGC to consistently have
>>> short pauses.
>>>
>> CMS sometimes takes quite a bit of tuning to run well. The goal of
>> CMS is to not have the full GC's (that would be analogous to the full
>> GC's with UseParallelGC or UseParallelOldGC).
>>
>>
>>> One thing to note is that our application has a large amount of long
>>> lived objects. My experience is that a lot of long lived objects make
>>> full collections longer.
>>>
>> This (plus the need for low pauses) would indicate that CMS may a good
>> choice although CMS works best when there is excess processing power
>> that CMS can use concurrently with the application. Does you
>> platform have 2 or 4 hardware threads?
>>
>>
>>> What are my options to consistently reduce the longest GC pauses?
>>>
>>> Would our application profile (lots of long lived objects) make it a
>>> good candidate for the coming lower collector aka G1?
>>>
>> Depends of lots of things but part of the design of G1 is
>> is to do collections of the heap in increments. You would
>> get shorter pauses that a full GC certainly but would get
>> more collections (more, shorter collections). G1 also does works
>> concurrently with application so having available processing
>> power helps.
>>
>>
>>
>>> Thanks in advance
>>>
>>> Alex Aisinzon
>>>
>>> -----Original Message-----
>>> From: hotspot-gc-use-bounces(a)openjdk.java.net
>>> [mailto:hotspot-gc-use-bounces@openjdk.java.net] On Behalf Of
>>> hotspot-gc-use-request(a)openjdk.java.net
>>> Sent: Wednesday, February 25, 2009 8:41 PM
>>> To: hotspot-gc-use(a)openjdk.java.net
>>> Subject: hotspot-gc-use Digest, Vol 15, Issue 7
>>>
>>> Send hotspot-gc-use mailing list submissions to
>>> hotspot-gc-use(a)openjdk.java.net
>>>
>>> To subscribe or unsubscribe via the World Wide Web, visit
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>> or, via email, send a message with subject or body 'help' to
>>> hotspot-gc-use-request(a)openjdk.java.net
>>>
>>> You can reach the person managing the list at
>>> hotspot-gc-use-owner(a)openjdk.java.net
>>>
>>> When replying, please edit your Subject line so it is more specific
>>> than "Re: Contents of hotspot-gc-use digest..."
>>>
>>>
>>> Today's Topics:
>>>
>>> 1. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application (Jon
>>>
>> Masamitsu)
>>
>>> 2. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application (Y Srinivas
>>> Ramakrishna)
>>>
>>>
>>>
>>>
> ----------------------------------------------------------------------
>
>>> Message: 1
>>> Date: Wed, 25 Feb 2009 14:42:32 -0800
>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>,
>>> hotspot-gc-use(a)openjdk.java.net
>>> Message-ID: <49A5C958.8070704(a)sun.com>
>>> Content-Type: text/plain; charset=us-ascii
>>>
>>> David,
>>>
>>> This is an educated guess but I would say that no out-of-memory
>>> was thrown because there was still significant space in the
>>> young gen after a collection.
>>>
>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)] [PSOldGen:
>>> 683678K->683678K(699072K)] 781918K->781918K(913792K) [PSPermGen:
>>>
>>> The young gen capacity being 214720K and the used space
>>> in the young gen being 98240K. That missing space may be in the
>>> survivor spaces which are not directly available to the
>>> application with the UseParallelGC collector. The logic
>>> that would throw the out-of-memory is very conservative
>>> and probably does not allow for such a case.
>>>
>>> Jon
>>>
>>>
>>>
>>> David Sitsky wrote On 02/25/09 13:59,:
>>>
>>>
>>>> Hi Ramki,
>>>>
>>>> The next message I posted to the hotspot list showed a GC trace when
>>>>
>> I
>>
>>>> allocated more memory (an extra 300 megs), where everything worked
>>>>
>>> fine.
>>>
>>>> I am well aware that the heap size for this particular application
>>>>
>>> and
>>>
>>>> data set was too small. My run from last night with the extra heap
>>>>
>> is
>>
>>>> still running nicely.
>>>>
>>>> I reported this issue, because it seemed to me no progress was being
>>>>
>
>
>>>> made and no OutOfMemoryErrors were being generated. The application
>>>>
>>> was
>>>
>>>> effectively "stuck" making no progress at all. I couldn't even
>>>>
>> connect
>>
>>>> to it with jconsole, although jstack worked fine.
>>>>
>>>> My understanding is this condition is meant to be detected, and
>>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>>>>
>>> This
>>>
>>>> is with the parallel GC.
>>>>
>>>> Cheers,
>>>> David
>>>>
>>>> Y Srinivas Ramakrishna wrote:
>>>>
>>>>
>>>>
>>>>> Doesn't the heap look too full?
>>>>> If a 64-bit JVM why use such an oversubscribed
>>>>> and small heap? Either make the old gen bigger or make the
>>>>> young gen smaller (giving that space to the older gen)
>>>>> so that each scavenge does not degenerate to a full gc
>>>>> as in your trace below.
>>>>>
>>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>>> so i have cross-posted over to that list with a bcc to
>>>>> the hotspot-dev list.
>>>>>
>>>>> Also the GC tuning guides to be found here might be useful
>>>>> reading:-
>>>>>
>>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>>
>>>>> -- ramki
>>>>>
>>>>> ----- Original Message -----
>>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>>>>
>>> platform within data processing application
>>>
>>>>> To: David Sitsky <sits(a)nuix.com>
>>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>>>>>
>>> <Thomas.Rodriguez(a)Sun.COM>
>>>
>>>>>
>>>>>
>>>>>
>>>>>> David,
>>>>>>
>>>>>> Can you also send a GC log from a run where there
>>>>>> is not a problem? As I understand it, that would
>>>>>> be a 32bit run.
>>>>>>
>>>>>> Jon
>>>>>>
>>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>> Jon Masamitsu wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> ...
>>>>>>>>>
>>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>>
>>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>> gathering the
>>>>>>
>>>>>>
>>>>>>
>>>>>>>>> GC logs.
>>>>>>>>> If you've already gathering some, send those but in future
>>>>>>>>>
> runs,
>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>> use the
>>>>>>
>>>>>>
>>>>>>
>>>>>>>>> above.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>> Here is a sample of output from a stuck process. You can see its
>>>>>>>
>
>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>> doing
>>>>>>
>>>>>>
>>>>>>
>>>>>>> a full GC about every 3 seconds, and it seems as if there is
>>>>>>>
>> little
>>
>>>>>>> progress..
>>>>>>>
>>>>>>> Please let me know if you need more information.
>>>>>>>
>>>>>>> Cheers,
>>>>>>> David
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>> _______________________________________________
>>>> hotspot-gc-use mailing list
>>>> hotspot-gc-use(a)openjdk.java.net
>>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>>
>>>>
>>>>
>>> ------------------------------
>>>
>>> Message: 2
>>> Date: Wed, 25 Feb 2009 20:41:10 -0800
>>> From: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: hotspot-gc-use(a)openjdk.java.net
>>> Message-ID: <71e0b0454a6.49a5ace6(a)sun.com>
>>> Content-Type: text/plain; charset=us-ascii
>>>
>>>
>>> Yes, sorry, my bad.
>>> I think Jon can explain that the trace you included
>>> will show metrics (GC overhead and Space free(d)) that somehow
>>> fall below the thresholds that trigger the GCOverhead related
>>> OOM. These thresholds can of course be modified via suitable
>>> JVM options.
>>>
>>> -- ramki
>>>
>>> ----- Original Message -----
>>> From: David Sitsky <sits(a)nuix.com>
>>> Date: Wednesday, February 25, 2009 1:59 pm
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>> To: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>>> Cc: hotspot-gc-use(a)openjdk.java.net
>>>
>>>
>>>
>>>> Hi Ramki,
>>>>
>>>> The next message I posted to the hotspot list showed a GC trace when
>>>>
>> I
>>
>>>> allocated more memory (an extra 300 megs), where everything worked
>>>> fine. I am well aware that the heap size for this particular
>>>> application and data set was too small. My run from last night with
>>>>
>
>
>>>> the extra heap is still running nicely.
>>>>
>>>> I reported this issue, because it seemed to me no progress was being
>>>>
>
>
>>>> made and no OutOfMemoryErrors were being generated. The application
>>>>
>
>
>>>> was effectively "stuck" making no progress at all. I couldn't even
>>>> connect to it with jconsole, although jstack worked fine.
>>>>
>>>> My understanding is this condition is meant to be detected, and
>>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>>>> This is with the parallel GC.
>>>>
>>>> Cheers,
>>>> David
>>>>
>>>> Y Srinivas Ramakrishna wrote:
>>>>
>>>>> Doesn't the heap look too full?
>>>>> If a 64-bit JVM why use such an oversubscribed
>>>>> and small heap? Either make the old gen bigger or make the
>>>>> young gen smaller (giving that space to the older gen)
>>>>> so that each scavenge does not degenerate to a full gc
>>>>> as in your trace below.
>>>>>
>>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>>> so i have cross-posted over to that list with a bcc to
>>>>> the hotspot-dev list.
>>>>>
>>>>> Also the GC tuning guides to be found here might be useful
>>>>> reading:-
>>>>>
>>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>>
>>>>> -- ramki
>>>>>
>>>>> ----- Original Message -----
>>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>>>>
>
>
>>>> platform within data processing application
>>>>
>>>>> To: David Sitsky <sits(a)nuix.com>
>>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>>>>>
>>> <Thomas.Rodriguez(a)Sun.COM>
>>>
>>>>>> David,
>>>>>>
>>>>>> Can you also send a GC log from a run where there
>>>>>> is not a problem? As I understand it, that would
>>>>>> be a 32bit run.
>>>>>>
>>>>>> Jon
>>>>>>
>>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>>
>>>>>>
>>>>>>> Jon Masamitsu wrote:
>>>>>>>
>>>>>>>
>>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> ...
>>>>>>>>>
>>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>>
>>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>>>>>
>>>>>> gathering the
>>>>>>
>>>>>>>>> GC logs.
>>>>>>>>> If you've already gathering some, send those but in future
>>>>>>>>>
> runs,
>
>>>>>> use the
>>>>>>
>>>>>>>>> above.
>>>>>>>>>
>>>>>>>>>
>>>>>>> Here is a sample of output from a stuck process. You can see its
>>>>>>>
>
>
>>>>>> doing
>>>>>>
>>>>>>> a full GC about every 3 seconds, and it seems as if there is
>>>>>>>
>> little
>>
>>>> progress..
>>>>
>>>>>>> Please let me know if you need more information.
>>>>>>>
>>>>>>> Cheers,
>>>>>>> David
>>>>>>>
>>>>>>> 62402.320: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8063178 secs] [Times:
>>>>
>> user=2.81
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62405.128: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8029997 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62407.932: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7917325 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62410.725: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891387 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62413.515: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7649110 secs] [Times:
>>>>
>> user=2.76
>>
>>>> sys=0.00, real=2.76 secs]
>>>>
>>>>>>> 62416.281: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7803983 secs] [Times:
>>>>
>> user=2.78
>>
>>>> sys=0.00, real=2.78 secs]
>>>>
>>>>>>> 62419.063: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7643979 secs] [Times:
>>>>
>> user=2.76
>>
>>>> sys=0.00, real=2.76 secs]
>>>>
>>>>>>> 62421.828: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8114336 secs] [Times:
>>>>
>> user=2.81
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62424.640: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7964912 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62427.438: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8107278 secs] [Times:
>>>>
>> user=2.81
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62430.249: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.2345212 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=3.24 secs]
>>>>
>>>>>>> 62433.484: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8341520 secs] [Times:
>>>>
>> user=2.82
>>
>>>> sys=0.00, real=2.82 secs]
>>>>
>>>>>>> 62436.319: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8698768 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62439.190: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9323230 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62442.124: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9644960 secs] [Times:
>>>>
>> user=2.96
>>
>>>> sys=0.00, real=2.96 secs]
>>>>
>>>>>>> 62445.089: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.0059221 secs] [Times:
>>>>
>> user=3.00
>>
>>>> sys=0.00, real=3.00 secs]
>>>>
>>>>>>> 62448.095: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9832815 secs] [Times:
>>>>
>> user=3.00
>>
>>>> sys=0.00, real=2.99 secs]
>>>>
>>>>>>> 62451.079: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9587156 secs] [Times:
>>>>
>> user=2.93
>>
>>>> sys=0.00, real=2.95 secs]
>>>>
>>>>>>> 62454.039: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9488345 secs] [Times:
>>>>
>> user=2.92
>>
>>>> sys=0.00, real=2.95 secs]
>>>>
>>>>>>> 62456.988: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8969788 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62459.886: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8794991 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62462.766: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8842411 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62465.651: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683675K(699072K)] 781916K->781915K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8669173 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.85 secs]
>>>>
>>>>>>> 62468.519: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8664429 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62471.386: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8844494 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62474.271: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8648398 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62477.137: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8971068 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62480.034: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8655618 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62482.901: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 3.0366140 secs] [Times:
>>>>
>> user=2.78
>>
>>>> sys=0.00, real=3.04 secs]
>>>>
>>>>>>> 62485.939: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8541753 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.85 secs]
>>>>
>>>>>>> 62488.794: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8582816 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62491.653: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8673218 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62494.521: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9014120 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62497.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805843 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62500.305: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8905128 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62503.196: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052007 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62506.102: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9004575 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62509.003: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9160655 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62511.920: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9013277 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62514.822: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982061 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62517.721: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8922437 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62520.614: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8873520 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62523.502: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805296 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62526.383: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8958714 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62529.279: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8735384 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62532.154: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8705676 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62535.025: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8723947 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62537.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8624400 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62540.761: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8245748 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62543.587: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8432269 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62546.432: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8394157 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62549.272: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8471951 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.85 secs]
>>>>
>>>>>>> 62552.121: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8584107 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62554.981: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8376807 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62557.820: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8402486 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62560.661: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8482704 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.85 secs]
>>>>
>>>>>>> 62563.511: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8115973 secs] [Times:
>>>>
>> user=2.81
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62566.324: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8523278 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62569.177: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8128563 secs] [Times:
>>>>
>> user=2.81
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62571.990: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7830644 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62574.774: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8065106 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62577.582: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892171 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62580.372: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8059306 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62583.179: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8641470 secs] [Times:
>>>>
>> user=2.82
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62586.044: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8421364 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62588.887: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8852699 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62591.773: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9164279 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62594.690: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9450010 secs] [Times:
>>>>
>> user=2.95
>>
>>>> sys=0.00, real=2.95 secs]
>>>>
>>>>>>> 62597.636: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9744636 secs] [Times:
>>>>
>> user=2.98
>>
>>>> sys=0.00, real=2.98 secs]
>>>>
>>>>>>> 62600.611: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9900849 secs] [Times:
>>>>
>> user=2.99
>>
>>>> sys=0.00, real=3.00 secs]
>>>>
>>>>>>> 62603.602: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.6332370 secs] [Times:
>>>>
>> user=2.62
>>
>>>> sys=0.00, real=2.62 secs]
>>>>
>>>>>>> 62606.236: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9801260 secs] [Times:
>>>>
>> user=2.95
>>
>>>> sys=0.00, real=2.98 secs]
>>>>
>>>>>>> 62609.226: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9166374 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62612.150: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9475729 secs] [Times:
>>>>
>> user=2.95
>>
>>>> sys=0.00, real=2.95 secs]
>>>>
>>>>>>> 62615.098: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9328670 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.93 secs]
>>>>
>>>>>>> 62618.040: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8963825 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62620.937: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8834715 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62623.821: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8800691 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62626.701: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683677K(699072K)] 781918K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8642587 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62629.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8574615 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62632.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8383412 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62635.264: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8409891 secs] [Times:
>>>>
>> user=2.82
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>>>>>> 62638.106: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7906216 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62640.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891730 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62643.688: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892940 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62646.479: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7766807 secs] [Times:
>>>>
>> user=2.78
>>
>>>> sys=0.00, real=2.78 secs]
>>>>
>>>>>>> 62649.257: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7796531 secs] [Times:
>>>>
>> user=2.78
>>
>>>> sys=0.00, real=2.78 secs]
>>>>
>>>>>>> 62652.037: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7687240 secs] [Times:
>>>>
>> user=2.76
>>
>>>> sys=0.00, real=2.76 secs]
>>>>
>>>>>>> 62654.807: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7613769 secs] [Times:
>>>>
>> user=2.76
>>
>>>> sys=0.00, real=2.76 secs]
>>>>
>>>>>>> 62657.570: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7712254 secs] [Times:
>>>>
>> user=2.78
>>
>>>> sys=0.00, real=2.78 secs]
>>>>
>>>>>>> 62660.342: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7968108 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62663.139: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.7924173 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.79 secs]
>>>>
>>>>>>> 62665.933: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8002912 secs] [Times:
>>>>
>> user=2.79
>>
>>>> sys=0.00, real=2.81 secs]
>>>>
>>>>>>> 62668.736: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8291434 secs] [Times:
>>>>
>> user=2.82
>>
>>>> sys=0.00, real=2.82 secs]
>>>>
>>>>>>> 62671.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8527186 secs] [Times:
>>>>
>> user=2.86
>>
>>>> sys=0.00, real=2.85 secs]
>>>>
>>>>>>> 62674.419: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982825 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62677.318: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9254483 secs] [Times:
>>>>
>> user=2.93
>>
>>>> sys=0.00, real=2.93 secs]
>>>>
>>>>>>> 62680.244: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9707015 secs] [Times:
>>>>
>> user=2.95
>>
>>>> sys=0.00, real=2.96 secs]
>>>>
>>>>>>> 62683.216: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9894145 secs] [Times:
>>>>
>> user=3.00
>>
>>>> sys=0.00, real=3.00 secs]
>>>>
>>>>>>> 62686.206: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9870305 secs] [Times:
>>>>
>> user=2.98
>>
>>>> sys=0.00, real=2.98 secs]
>>>>
>>>>>>> 62689.193: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9884647 secs] [Times:
>>>>
>> user=2.98
>>
>>>> sys=0.00, real=3.00 secs]
>>>>
>>>>>>> 62692.183: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9635276 secs] [Times:
>>>>
>> user=2.96
>>
>>>> sys=0.00, real=2.96 secs]
>>>>
>>>>>>> 62695.147: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9407559 secs] [Times:
>>>>
>> user=2.93
>>
>>>> sys=0.00, real=2.93 secs]
>>>>
>>>>>>> 62698.088: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9299386 secs] [Times:
>>>>
>> user=2.93
>>
>>>> sys=0.00, real=2.93 secs]
>>>>
>>>>>>> 62701.019: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8994903 secs] [Times:
>>>>
>> user=2.90
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62703.919: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9163417 secs] [Times:
>>>>
>> user=2.92
>>
>>>> sys=0.00, real=2.92 secs]
>>>>
>>>>>>> 62706.836: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9216473 secs] [Times:
>>>>
>> user=2.93
>>
>>>> sys=0.00, real=2.93 secs]
>>>>
>>>>>>> 62709.758: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052547 secs] [Times:
>>>>
>> user=2.89
>>
>>>> sys=0.00, real=2.90 secs]
>>>>
>>>>>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8902824 secs] [Times:
>>>>
>> user=2.85
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62715.555: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8865932 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.89 secs]
>>>>
>>>>>>> 62718.442: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8605445 secs] [Times:
>>>>
>> user=2.87
>>
>>>> sys=0.00, real=2.87 secs]
>>>>
>>>>>>> 62721.304: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8662771 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.86 secs]
>>>>
>>>>>>> 62724.171: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>>>>>>
>>>> [PSOldGen: 683679K->683679K(699072K)] 781919K->781919K(913792K)
>>>> [PSPermGen: 49694K->49694K(49984K)], 2.8369076 secs] [Times:
>>>>
>> user=2.84
>>
>>>> sys=0.00, real=2.84 secs]
>>>>
>>> ------------------------------
>>>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use(a)openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>
>>>
>>> End of hotspot-gc-use Digest, Vol 15, Issue 7
>>> *********************************************
>>>
>>>
>>>
>>>
> ------------------------------------------------------------------------
>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use(a)openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use(a)openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use(a)openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
1
0
On 03/10/09 09:36, Alex Aisinzon wrote:
> Jon
>
> As always, your feedback is always enlightening and very much
> appreciated.
> I have some additional comments/questions before closing that
> conversation thread:
> The server has 2 cores. We have servers with more cores (4 and 8) and
> will likely run some tests with those. On these servers, ParallelOldGC
> may or may not prove better performing for the following reason: while I
> used a single JVM on that 2 cores server, we would use 4 JVMs on an 8
> core server (same ratio of one JVM for 2 cores). In that case, the many
> threads used during a full GC would compete for resources with the other
> running JVMs.
Yes, multiple VM's doing GC's at the same time will
compete for resources. That's not just true for UseParallelOldGC.
It's also the case with UseParallelGC where parallel GC threads
are used for the young gen collection. Consider setting
ParallelGCThreads explicitly if you frequent instances of poor
scaling (i.e., if you look at the user time and the real time
and they show little scaling).
> Some Sun benchmarks (by example
> http://www.spec.org/jbb2005/results/res2008q2/jbb2005-20080506-00485.htm
> l) infer that ParallelOldGC may be beneficial even with 2 cores. My
> hypothesis is that this is because the application tested (the
> SPECJBB2005 code) uses much fewer longer lived objects, as shown by the
> JVM tunings (-Xmx3350m -Xms3350m -Xmn2800m infers that the tenured is
> only 550MB large).
That benchmark benefits from the young generation parallel GC
(UseParallelGC) which scales better than the old generation
parallel GC. Also, as you note, much of the data is short
lived so gets collected by the young generation collections.
>
> Thanks again for your thoughts.
If you do anymore CMS experiments, send me a log and
I'll look to see if it is worth pursuing.
>
> Regards
>
> Alex Aisinzon
>
> -----Original Message-----
> From: Jon.Masamitsu(a)Sun.COM [mailto:Jon.Masamitsu@Sun.COM]
> Sent: Tuesday, March 10, 2009 8:57 AM
> To: Alex Aisinzon
> Cc: hotspot-gc-use(a)openjdk.java.net
> Subject: Re: Scalability issues with ParallelOld
>
>
>
> On 03/09/09 16:14, Alex Aisinzon wrote:
>> Hi all
>>
>> I try to am experimenting with ParallelOldGC in our performance
> testing
>> environment.
>> The server is a Dual Core Opteron 280 (old hardware with few cores by
>> today's standard).
>> With Sun JDK 1.5, full collections with ParallelGC and 2 GC threads
> last
>> between 5 & 7 seconds. I tried used ParallelOld with 2 GC threads. The
>> full collections are almost twice the time.
>> I then tried with Sun JDK 1.6 to see if it was any better. It is not
>> significantly
>
> In the logs with UseParallelOldGC I see an average major pause of about
> 14 sec with 1.5 and about 9.3 sec with 1.6. That's about the
> improvement I would expect.
>
> With UseParallelOldGC using 2 GC threads is about the break even point.
> That depends on the application. I would not expect using 2 GC threads
> with UseParallelOldGC to be better than UseParallelGC. UseParallelOldGC
> does do more work. If you look at the last entry in the 1.6 log
>
> 3034.907: [Full GC [PSYoungGen: 12157K->0K(276160K)] [ParOldGen:
> 2324556K->828465K(2330176K)] 2336714K->828465K(2606336K) [PSPermGen:
> 82577K->82549K(102400K)], 9.0664330 secs] [Times: user=16.81 sys=0.03,
> real=9.07 secs]
>
> the user time is 16.81 secs and the real time is 9 secs so that says to
> me that we have both GC threads working in parallel and perhaps doing
> twice the work of the UseParallelGC on a full collection.
>
>
>> I have enclosed the logs (Sun JDK 1.5 with ParallelGC and
> ParallelOldGC
>> and Sun JDK 1.6 with ParallelOldGC).
>>
>> I have also experimented with CMS with mixed results: I could not get
> it
>> to work when using the 64 bit release and double the heap. With 32
> bit,
>> it experienced some rare but longer pauses than ParallelGC. Therefore,
>> it did not seem a good alternative to ParallelGC to consistently have
>> short pauses.
>
> CMS sometimes takes quite a bit of tuning to run well. The goal of
> CMS is to not have the full GC's (that would be analogous to the full
> GC's with UseParallelGC or UseParallelOldGC).
>
>> One thing to note is that our application has a large amount of long
>> lived objects. My experience is that a lot of long lived objects make
>> full collections longer.
>
> This (plus the need for low pauses) would indicate that CMS may a good
> choice although CMS works best when there is excess processing power
> that CMS can use concurrently with the application. Does you
> platform have 2 or 4 hardware threads?
>
>> What are my options to consistently reduce the longest GC pauses?
>>
>> Would our application profile (lots of long lived objects) make it a
>> good candidate for the coming lower collector aka G1?
>
> Depends of lots of things but part of the design of G1 is
> is to do collections of the heap in increments. You would
> get shorter pauses that a full GC certainly but would get
> more collections (more, shorter collections). G1 also does works
> concurrently with application so having available processing
> power helps.
>
>
>> Thanks in advance
>>
>> Alex Aisinzon
>>
>> -----Original Message-----
>> From: hotspot-gc-use-bounces(a)openjdk.java.net
>> [mailto:hotspot-gc-use-bounces@openjdk.java.net] On Behalf Of
>> hotspot-gc-use-request(a)openjdk.java.net
>> Sent: Wednesday, February 25, 2009 8:41 PM
>> To: hotspot-gc-use(a)openjdk.java.net
>> Subject: hotspot-gc-use Digest, Vol 15, Issue 7
>>
>> Send hotspot-gc-use mailing list submissions to
>> hotspot-gc-use(a)openjdk.java.net
>>
>> To subscribe or unsubscribe via the World Wide Web, visit
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>> or, via email, send a message with subject or body 'help' to
>> hotspot-gc-use-request(a)openjdk.java.net
>>
>> You can reach the person managing the list at
>> hotspot-gc-use-owner(a)openjdk.java.net
>>
>> When replying, please edit your Subject line so it is more specific
>> than "Re: Contents of hotspot-gc-use digest..."
>>
>>
>> Today's Topics:
>>
>> 1. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application (Jon
> Masamitsu)
>> 2. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application (Y Srinivas
>> Ramakrishna)
>>
>>
>> ----------------------------------------------------------------------
>>
>> Message: 1
>> Date: Wed, 25 Feb 2009 14:42:32 -0800
>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application
>> To: David Sitsky <sits(a)nuix.com>
>> Cc: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>,
>> hotspot-gc-use(a)openjdk.java.net
>> Message-ID: <49A5C958.8070704(a)sun.com>
>> Content-Type: text/plain; charset=us-ascii
>>
>> David,
>>
>> This is an educated guess but I would say that no out-of-memory
>> was thrown because there was still significant space in the
>> young gen after a collection.
>>
>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)] [PSOldGen:
>> 683678K->683678K(699072K)] 781918K->781918K(913792K) [PSPermGen:
>>
>> The young gen capacity being 214720K and the used space
>> in the young gen being 98240K. That missing space may be in the
>> survivor spaces which are not directly available to the
>> application with the UseParallelGC collector. The logic
>> that would throw the out-of-memory is very conservative
>> and probably does not allow for such a case.
>>
>> Jon
>>
>>
>>
>> David Sitsky wrote On 02/25/09 13:59,:
>>
>>> Hi Ramki,
>>>
>>> The next message I posted to the hotspot list showed a GC trace when
> I
>>> allocated more memory (an extra 300 megs), where everything worked
>> fine.
>>> I am well aware that the heap size for this particular application
>> and
>>> data set was too small. My run from last night with the extra heap
> is
>>> still running nicely.
>>>
>>> I reported this issue, because it seemed to me no progress was being
>>> made and no OutOfMemoryErrors were being generated. The application
>> was
>>> effectively "stuck" making no progress at all. I couldn't even
> connect
>>> to it with jconsole, although jstack worked fine.
>>>
>>> My understanding is this condition is meant to be detected, and
>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>> This
>>> is with the parallel GC.
>>>
>>> Cheers,
>>> David
>>>
>>> Y Srinivas Ramakrishna wrote:
>>>
>>>
>>>> Doesn't the heap look too full?
>>>> If a 64-bit JVM why use such an oversubscribed
>>>> and small heap? Either make the old gen bigger or make the
>>>> young gen smaller (giving that space to the older gen)
>>>> so that each scavenge does not degenerate to a full gc
>>>> as in your trace below.
>>>>
>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>> so i have cross-posted over to that list with a bcc to
>>>> the hotspot-dev list.
>>>>
>>>> Also the GC tuning guides to be found here might be useful
>>>> reading:-
>>>>
>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>
>>>> -- ramki
>>>>
>>>> ----- Original Message -----
>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application
>>>> To: David Sitsky <sits(a)nuix.com>
>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>> <Thomas.Rodriguez(a)Sun.COM>
>>>>
>>>>
>>>>> David,
>>>>>
>>>>> Can you also send a GC log from a run where there
>>>>> is not a problem? As I understand it, that would
>>>>> be a 32bit run.
>>>>>
>>>>> Jon
>>>>>
>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>
>>>>>
>>>>>
>>>>>> Jon Masamitsu wrote:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> ...
>>>>>>>>
>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>
>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>>>>
>>>>>>>>
>>>>> gathering the
>>>>>
>>>>>
>>>>>>>> GC logs.
>>>>>>>> If you've already gathering some, send those but in future runs,
>
>>>>>>>>
>>>>>>>>
>>>>> use the
>>>>>
>>>>>
>>>>>>>> above.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>> Here is a sample of output from a stuck process. You can see its
>>>>>>
>>>>>>
>>>>> doing
>>>>>
>>>>>
>>>>>> a full GC about every 3 seconds, and it seems as if there is
> little
>>>>>> progress..
>>>>>>
>>>>>> Please let me know if you need more information.
>>>>>>
>>>>>> Cheers,
>>>>>> David
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use(a)openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>
>>>
>>
>>
>> ------------------------------
>>
>> Message: 2
>> Date: Wed, 25 Feb 2009 20:41:10 -0800
>> From: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application
>> To: David Sitsky <sits(a)nuix.com>
>> Cc: hotspot-gc-use(a)openjdk.java.net
>> Message-ID: <71e0b0454a6.49a5ace6(a)sun.com>
>> Content-Type: text/plain; charset=us-ascii
>>
>>
>> Yes, sorry, my bad.
>> I think Jon can explain that the trace you included
>> will show metrics (GC overhead and Space free(d)) that somehow
>> fall below the thresholds that trigger the GCOverhead related
>> OOM. These thresholds can of course be modified via suitable
>> JVM options.
>>
>> -- ramki
>>
>> ----- Original Message -----
>> From: David Sitsky <sits(a)nuix.com>
>> Date: Wednesday, February 25, 2009 1:59 pm
>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application
>> To: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
>> Cc: hotspot-gc-use(a)openjdk.java.net
>>
>>
>>> Hi Ramki,
>>>
>>> The next message I posted to the hotspot list showed a GC trace when
> I
>>> allocated more memory (an extra 300 megs), where everything worked
>>> fine. I am well aware that the heap size for this particular
>>> application and data set was too small. My run from last night with
>>> the extra heap is still running nicely.
>>>
>>> I reported this issue, because it seemed to me no progress was being
>>> made and no OutOfMemoryErrors were being generated. The application
>>> was effectively "stuck" making no progress at all. I couldn't even
>>> connect to it with jconsole, although jstack worked fine.
>>>
>>> My understanding is this condition is meant to be detected, and
>>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>>> This is with the parallel GC.
>>>
>>> Cheers,
>>> David
>>>
>>> Y Srinivas Ramakrishna wrote:
>>>> Doesn't the heap look too full?
>>>> If a 64-bit JVM why use such an oversubscribed
>>>> and small heap? Either make the old gen bigger or make the
>>>> young gen smaller (giving that space to the older gen)
>>>> so that each scavenge does not degenerate to a full gc
>>>> as in your trace below.
>>>>
>>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>>> so i have cross-posted over to that list with a bcc to
>>>> the hotspot-dev list.
>>>>
>>>> Also the GC tuning guides to be found here might be useful
>>>> reading:-
>>>>
>>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>>
>>>> -- ramki
>>>>
>>>> ----- Original Message -----
>>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>>> Date: Tuesday, February 24, 2009 10:00 pm
>>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>>> platform within data processing application
>>>> To: David Sitsky <sits(a)nuix.com>
>>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
>> <Thomas.Rodriguez(a)Sun.COM>
>>>>> David,
>>>>>
>>>>> Can you also send a GC log from a run where there
>>>>> is not a problem? As I understand it, that would
>>>>> be a 32bit run.
>>>>>
>>>>> Jon
>>>>>
>>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>>
>>>>>> Jon Masamitsu wrote:
>>>>>>
>>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>>
>>>>>>>
>>>>>>>> ...
>>>>>>>>
>>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>>
>>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>> gathering the
>>>>>>>> GC logs.
>>>>>>>> If you've already gathering some, send those but in future runs,
>
>>>>> use the
>>>>>>>> above.
>>>>>>>>
>>>>>> Here is a sample of output from a stuck process. You can see its
>>>>> doing
>>>>>> a full GC about every 3 seconds, and it seems as if there is
> little
>>> progress..
>>>>>> Please let me know if you need more information.
>>>>>>
>>>>>> Cheers,
>>>>>> David
>>>>>>
>>>>>> 62402.320: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8063178 secs] [Times:
> user=2.81
>>> sys=0.00, real=2.81 secs]
>>>>>> 62405.128: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8029997 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.81 secs]
>>>>>> 62407.932: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7917325 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62410.725: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891387 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62413.515: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7649110 secs] [Times:
> user=2.76
>>> sys=0.00, real=2.76 secs]
>>>>>> 62416.281: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7803983 secs] [Times:
> user=2.78
>>> sys=0.00, real=2.78 secs]
>>>>>> 62419.063: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7643979 secs] [Times:
> user=2.76
>>> sys=0.00, real=2.76 secs]
>>>>>> 62421.828: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8114336 secs] [Times:
> user=2.81
>>> sys=0.00, real=2.81 secs]
>>>>>> 62424.640: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7964912 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62427.438: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8107278 secs] [Times:
> user=2.81
>>> sys=0.00, real=2.81 secs]
>>>>>> 62430.249: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 3.2345212 secs] [Times:
> user=2.84
>>> sys=0.00, real=3.24 secs]
>>>>>> 62433.484: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8341520 secs] [Times:
> user=2.82
>>> sys=0.00, real=2.82 secs]
>>>>>> 62436.319: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8698768 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.87 secs]
>>>>>> 62439.190: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9323230 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.92 secs]
>>>>>> 62442.124: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9644960 secs] [Times:
> user=2.96
>>> sys=0.00, real=2.96 secs]
>>>>>> 62445.089: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 3.0059221 secs] [Times:
> user=3.00
>>> sys=0.00, real=3.00 secs]
>>>>>> 62448.095: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9832815 secs] [Times:
> user=3.00
>>> sys=0.00, real=2.99 secs]
>>>>>> 62451.079: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9587156 secs] [Times:
> user=2.93
>>> sys=0.00, real=2.95 secs]
>>>>>> 62454.039: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9488345 secs] [Times:
> user=2.92
>>> sys=0.00, real=2.95 secs]
>>>>>> 62456.988: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8969788 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.90 secs]
>>>>>> 62459.886: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8794991 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62462.766: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8842411 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.89 secs]
>>>>>> 62465.651: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683675K(699072K)] 781916K->781915K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8669173 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.85 secs]
>>>>>> 62468.519: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8664429 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.86 secs]
>>>>>> 62471.386: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8844494 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.89 secs]
>>>>>> 62474.271: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8648398 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.87 secs]
>>>>>> 62477.137: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8971068 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.90 secs]
>>>>>> 62480.034: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8655618 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.86 secs]
>>>>>> 62482.901: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 3.0366140 secs] [Times:
> user=2.78
>>> sys=0.00, real=3.04 secs]
>>>>>> 62485.939: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8541753 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.85 secs]
>>>>>> 62488.794: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8582816 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.86 secs]
>>>>>> 62491.653: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8673218 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.86 secs]
>>>>>> 62494.521: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9014120 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.90 secs]
>>>>>> 62497.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805843 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62500.305: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8905128 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62503.196: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052007 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.92 secs]
>>>>>> 62506.102: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9004575 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.90 secs]
>>>>>> 62509.003: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9160655 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.92 secs]
>>>>>> 62511.920: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9013277 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.90 secs]
>>>>>> 62514.822: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982061 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62517.721: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8922437 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62520.614: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8873520 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.89 secs]
>>>>>> 62523.502: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8805296 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62526.383: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8958714 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.89 secs]
>>>>>> 62529.279: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8735384 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62532.154: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8705676 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.87 secs]
>>>>>> 62535.025: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8723947 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.87 secs]
>>>>>> 62537.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8624400 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.86 secs]
>>>>>> 62540.761: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8245748 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62543.587: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8432269 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62546.432: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8394157 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62549.272: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8471951 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.85 secs]
>>>>>> 62552.121: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8584107 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.86 secs]
>>>>>> 62554.981: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8376807 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62557.820: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8402486 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62560.661: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8482704 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.85 secs]
>>>>>> 62563.511: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8115973 secs] [Times:
> user=2.81
>>> sys=0.00, real=2.81 secs]
>>>>>> 62566.324: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8523278 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.86 secs]
>>>>>> 62569.177: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8128563 secs] [Times:
> user=2.81
>>> sys=0.00, real=2.81 secs]
>>>>>> 62571.990: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7830644 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62574.774: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8065106 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.81 secs]
>>>>>> 62577.582: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892171 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62580.372: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8059306 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62583.179: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8641470 secs] [Times:
> user=2.82
>>> sys=0.00, real=2.86 secs]
>>>>>> 62586.044: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8421364 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62588.887: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8852699 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62591.773: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9164279 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.92 secs]
>>>>>> 62594.690: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9450010 secs] [Times:
> user=2.95
>>> sys=0.00, real=2.95 secs]
>>>>>> 62597.636: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9744636 secs] [Times:
> user=2.98
>>> sys=0.00, real=2.98 secs]
>>>>>> 62600.611: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9900849 secs] [Times:
> user=2.99
>>> sys=0.00, real=3.00 secs]
>>>>>> 62603.602: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.6332370 secs] [Times:
> user=2.62
>>> sys=0.00, real=2.62 secs]
>>>>>> 62606.236: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9801260 secs] [Times:
> user=2.95
>>> sys=0.00, real=2.98 secs]
>>>>>> 62609.226: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9166374 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.92 secs]
>>>>>> 62612.150: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9475729 secs] [Times:
> user=2.95
>>> sys=0.00, real=2.95 secs]
>>>>>> 62615.098: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9328670 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.93 secs]
>>>>>> 62618.040: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8963825 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.90 secs]
>>>>>> 62620.937: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8834715 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.89 secs]
>>>>>> 62623.821: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8800691 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.87 secs]
>>>>>> 62626.701: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683677K(699072K)] 781918K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8642587 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.87 secs]
>>>>>> 62629.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8574615 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.86 secs]
>>>>>> 62632.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8383412 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>>>>> 62635.264: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8409891 secs] [Times:
> user=2.82
>>> sys=0.00, real=2.84 secs]
>>>>>> 62638.106: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7906216 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62640.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7891730 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62643.688: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7892940 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62646.479: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7766807 secs] [Times:
> user=2.78
>>> sys=0.00, real=2.78 secs]
>>>>>> 62649.257: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7796531 secs] [Times:
> user=2.78
>>> sys=0.00, real=2.78 secs]
>>>>>> 62652.037: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7687240 secs] [Times:
> user=2.76
>>> sys=0.00, real=2.76 secs]
>>>>>> 62654.807: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7613769 secs] [Times:
> user=2.76
>>> sys=0.00, real=2.76 secs]
>>>>>> 62657.570: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7712254 secs] [Times:
> user=2.78
>>> sys=0.00, real=2.78 secs]
>>>>>> 62660.342: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7968108 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62663.139: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.7924173 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.79 secs]
>>>>>> 62665.933: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8002912 secs] [Times:
> user=2.79
>>> sys=0.00, real=2.81 secs]
>>>>>> 62668.736: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8291434 secs] [Times:
> user=2.82
>>> sys=0.00, real=2.82 secs]
>>>>>> 62671.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8527186 secs] [Times:
> user=2.86
>>> sys=0.00, real=2.85 secs]
>>>>>> 62674.419: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8982825 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.90 secs]
>>>>>> 62677.318: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9254483 secs] [Times:
> user=2.93
>>> sys=0.00, real=2.93 secs]
>>>>>> 62680.244: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9707015 secs] [Times:
> user=2.95
>>> sys=0.00, real=2.96 secs]
>>>>>> 62683.216: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9894145 secs] [Times:
> user=3.00
>>> sys=0.00, real=3.00 secs]
>>>>>> 62686.206: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9870305 secs] [Times:
> user=2.98
>>> sys=0.00, real=2.98 secs]
>>>>>> 62689.193: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9884647 secs] [Times:
> user=2.98
>>> sys=0.00, real=3.00 secs]
>>>>>> 62692.183: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9635276 secs] [Times:
> user=2.96
>>> sys=0.00, real=2.96 secs]
>>>>>> 62695.147: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9407559 secs] [Times:
> user=2.93
>>> sys=0.00, real=2.93 secs]
>>>>>> 62698.088: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9299386 secs] [Times:
> user=2.93
>>> sys=0.00, real=2.93 secs]
>>>>>> 62701.019: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8994903 secs] [Times:
> user=2.90
>>> sys=0.00, real=2.90 secs]
>>>>>> 62703.919: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9163417 secs] [Times:
> user=2.92
>>> sys=0.00, real=2.92 secs]
>>>>>> 62706.836: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9216473 secs] [Times:
> user=2.93
>>> sys=0.00, real=2.93 secs]
>>>>>> 62709.758: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.9052547 secs] [Times:
> user=2.89
>>> sys=0.00, real=2.90 secs]
>>>>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8902824 secs] [Times:
> user=2.85
>>> sys=0.00, real=2.89 secs]
>>>>>> 62715.555: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8865932 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.89 secs]
>>>>>> 62718.442: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8605445 secs] [Times:
> user=2.87
>>> sys=0.00, real=2.87 secs]
>>>>>> 62721.304: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8662771 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.86 secs]
>>>>>> 62724.171: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>>> [PSOldGen: 683679K->683679K(699072K)] 781919K->781919K(913792K)
>>> [PSPermGen: 49694K->49694K(49984K)], 2.8369076 secs] [Times:
> user=2.84
>>> sys=0.00, real=2.84 secs]
>>
>> ------------------------------
>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use(a)openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>>
>> End of hotspot-gc-use Digest, Vol 15, Issue 7
>> *********************************************
>>
>>
>>
> ------------------------------------------------------------------------
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use(a)openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use(a)openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
1
0
On 03/09/09 16:14, Alex Aisinzon wrote:
> Hi all
>
> I try to am experimenting with ParallelOldGC in our performance testing
> environment.
> The server is a Dual Core Opteron 280 (old hardware with few cores by
> today's standard).
> With Sun JDK 1.5, full collections with ParallelGC and 2 GC threads last
> between 5 & 7 seconds. I tried used ParallelOld with 2 GC threads. The
> full collections are almost twice the time.
> I then tried with Sun JDK 1.6 to see if it was any better. It is not
> significantly
In the logs with UseParallelOldGC I see an average major pause of about
14 sec with 1.5 and about 9.3 sec with 1.6. That's about the
improvement I would expect.
With UseParallelOldGC using 2 GC threads is about the break even point.
That depends on the application. I would not expect using 2 GC threads
with UseParallelOldGC to be better than UseParallelGC. UseParallelOldGC
does do more work. If you look at the last entry in the 1.6 log
3034.907: [Full GC [PSYoungGen: 12157K->0K(276160K)] [ParOldGen:
2324556K->828465K(2330176K)] 2336714K->828465K(2606336K) [PSPermGen:
82577K->82549K(102400K)], 9.0664330 secs] [Times: user=16.81 sys=0.03,
real=9.07 secs]
the user time is 16.81 secs and the real time is 9 secs so that says to
me that we have both GC threads working in parallel and perhaps doing
twice the work of the UseParallelGC on a full collection.
> I have enclosed the logs (Sun JDK 1.5 with ParallelGC and ParallelOldGC
> and Sun JDK 1.6 with ParallelOldGC).
>
> I have also experimented with CMS with mixed results: I could not get it
> to work when using the 64 bit release and double the heap. With 32 bit,
> it experienced some rare but longer pauses than ParallelGC. Therefore,
> it did not seem a good alternative to ParallelGC to consistently have
> short pauses.
CMS sometimes takes quite a bit of tuning to run well. The goal of
CMS is to not have the full GC's (that would be analogous to the full
GC's with UseParallelGC or UseParallelOldGC).
>
> One thing to note is that our application has a large amount of long
> lived objects. My experience is that a lot of long lived objects make
> full collections longer.
This (plus the need for low pauses) would indicate that CMS may a good
choice although CMS works best when there is excess processing power
that CMS can use concurrently with the application. Does you
platform have 2 or 4 hardware threads?
>
> What are my options to consistently reduce the longest GC pauses?
>
> Would our application profile (lots of long lived objects) make it a
> good candidate for the coming lower collector aka G1?
Depends of lots of things but part of the design of G1 is
is to do collections of the heap in increments. You would
get shorter pauses that a full GC certainly but would get
more collections (more, shorter collections). G1 also does works
concurrently with application so having available processing
power helps.
>
> Thanks in advance
>
> Alex Aisinzon
>
> -----Original Message-----
> From: hotspot-gc-use-bounces(a)openjdk.java.net
> [mailto:hotspot-gc-use-bounces@openjdk.java.net] On Behalf Of
> hotspot-gc-use-request(a)openjdk.java.net
> Sent: Wednesday, February 25, 2009 8:41 PM
> To: hotspot-gc-use(a)openjdk.java.net
> Subject: hotspot-gc-use Digest, Vol 15, Issue 7
>
> Send hotspot-gc-use mailing list submissions to
> hotspot-gc-use(a)openjdk.java.net
>
> To subscribe or unsubscribe via the World Wide Web, visit
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
> or, via email, send a message with subject or body 'help' to
> hotspot-gc-use-request(a)openjdk.java.net
>
> You can reach the person managing the list at
> hotspot-gc-use-owner(a)openjdk.java.net
>
> When replying, please edit your Subject line so it is more specific
> than "Re: Contents of hotspot-gc-use digest..."
>
>
> Today's Topics:
>
> 1. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application (Jon Masamitsu)
> 2. Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application (Y Srinivas
> Ramakrishna)
>
>
> ----------------------------------------------------------------------
>
> Message: 1
> Date: Wed, 25 Feb 2009 14:42:32 -0800
> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application
> To: David Sitsky <sits(a)nuix.com>
> Cc: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>,
> hotspot-gc-use(a)openjdk.java.net
> Message-ID: <49A5C958.8070704(a)sun.com>
> Content-Type: text/plain; charset=us-ascii
>
> David,
>
> This is an educated guess but I would say that no out-of-memory
> was thrown because there was still significant space in the
> young gen after a collection.
>
> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)] [PSOldGen:
> 683678K->683678K(699072K)] 781918K->781918K(913792K) [PSPermGen:
>
> The young gen capacity being 214720K and the used space
> in the young gen being 98240K. That missing space may be in the
> survivor spaces which are not directly available to the
> application with the UseParallelGC collector. The logic
> that would throw the out-of-memory is very conservative
> and probably does not allow for such a case.
>
> Jon
>
>
>
> David Sitsky wrote On 02/25/09 13:59,:
>
>> Hi Ramki,
>>
>> The next message I posted to the hotspot list showed a GC trace when I
>> allocated more memory (an extra 300 megs), where everything worked
> fine.
>> I am well aware that the heap size for this particular application
> and
>> data set was too small. My run from last night with the extra heap is
>> still running nicely.
>>
>> I reported this issue, because it seemed to me no progress was being
>> made and no OutOfMemoryErrors were being generated. The application
> was
>> effectively "stuck" making no progress at all. I couldn't even connect
>
>> to it with jconsole, although jstack worked fine.
>>
>> My understanding is this condition is meant to be detected, and
>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
> This
>> is with the parallel GC.
>>
>> Cheers,
>> David
>>
>> Y Srinivas Ramakrishna wrote:
>>
>>
>>> Doesn't the heap look too full?
>>> If a 64-bit JVM why use such an oversubscribed
>>> and small heap? Either make the old gen bigger or make the
>>> young gen smaller (giving that space to the older gen)
>>> so that each scavenge does not degenerate to a full gc
>>> as in your trace below.
>>>
>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>> so i have cross-posted over to that list with a bcc to
>>> the hotspot-dev list.
>>>
>>> Also the GC tuning guides to be found here might be useful
>>> reading:-
>>>
>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>
>>> -- ramki
>>>
>>> ----- Original Message -----
>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>> Date: Tuesday, February 24, 2009 10:00 pm
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
> <Thomas.Rodriguez(a)Sun.COM>
>>>
>>>
>>>
>>>> David,
>>>>
>>>> Can you also send a GC log from a run where there
>>>> is not a problem? As I understand it, that would
>>>> be a 32bit run.
>>>>
>>>> Jon
>>>>
>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>
>>>>
>>>>
>>>>> Jon Masamitsu wrote:
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>> ...
>>>>>>>
>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>
>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>>>>>
>>>>>>>
>>>> gathering the
>>>>
>>>>
>>>>>>> GC logs.
>>>>>>> If you've already gathering some, send those but in future runs,
>>>>>>>
>>>>>>>
>>>> use the
>>>>
>>>>
>>>>>>> above.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>> Here is a sample of output from a stuck process. You can see its
>>>>>
>>>>>
>>>> doing
>>>>
>>>>
>>>>> a full GC about every 3 seconds, and it seems as if there is little
>>>>> progress..
>>>>>
>>>>> Please let me know if you need more information.
>>>>>
>>>>> Cheers,
>>>>> David
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use(a)openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>>
>
>
>
> ------------------------------
>
> Message: 2
> Date: Wed, 25 Feb 2009 20:41:10 -0800
> From: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application
> To: David Sitsky <sits(a)nuix.com>
> Cc: hotspot-gc-use(a)openjdk.java.net
> Message-ID: <71e0b0454a6.49a5ace6(a)sun.com>
> Content-Type: text/plain; charset=us-ascii
>
>
> Yes, sorry, my bad.
> I think Jon can explain that the trace you included
> will show metrics (GC overhead and Space free(d)) that somehow
> fall below the thresholds that trigger the GCOverhead related
> OOM. These thresholds can of course be modified via suitable
> JVM options.
>
> -- ramki
>
> ----- Original Message -----
> From: David Sitsky <sits(a)nuix.com>
> Date: Wednesday, February 25, 2009 1:59 pm
> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
> platform within data processing application
> To: Y Srinivas Ramakrishna <Y.S.Ramakrishna(a)Sun.COM>
> Cc: hotspot-gc-use(a)openjdk.java.net
>
>
>> Hi Ramki,
>>
>> The next message I posted to the hotspot list showed a GC trace when I
>
>> allocated more memory (an extra 300 megs), where everything worked
>> fine. I am well aware that the heap size for this particular
>> application and data set was too small. My run from last night with
>> the extra heap is still running nicely.
>>
>> I reported this issue, because it seemed to me no progress was being
>> made and no OutOfMemoryErrors were being generated. The application
>> was effectively "stuck" making no progress at all. I couldn't even
>> connect to it with jconsole, although jstack worked fine.
>>
>> My understanding is this condition is meant to be detected, and
>> OutOfMemoryError is meant to be thrown, but perhaps I am mistaken?
>> This is with the parallel GC.
>>
>> Cheers,
>> David
>>
>> Y Srinivas Ramakrishna wrote:
>>> Doesn't the heap look too full?
>>> If a 64-bit JVM why use such an oversubscribed
>>> and small heap? Either make the old gen bigger or make the
>>> young gen smaller (giving that space to the older gen)
>>> so that each scavenge does not degenerate to a full gc
>>> as in your trace below.
>>>
>>> This discussion probably belongs on hotspot-gc-use(a)o.j.n list
>>> so i have cross-posted over to that list with a bcc to
>>> the hotspot-dev list.
>>>
>>> Also the GC tuning guides to be found here might be useful
>>> reading:-
>>>
>>> http://java.sun.com/javase/technologies/hotspot/gc/index.jsp
>>>
>>> -- ramki
>>>
>>> ----- Original Message -----
>>> From: Jon Masamitsu <Jon.Masamitsu(a)Sun.COM>
>>> Date: Tuesday, February 24, 2009 10:00 pm
>>> Subject: Re: 100% CPU usage in "VM Thread" for Hotspot 10/11 on x64
>> platform within data processing application
>>> To: David Sitsky <sits(a)nuix.com>
>>> Cc: hotspot-dev(a)openjdk.java.net, Tom Rodriguez
> <Thomas.Rodriguez(a)Sun.COM>
>>>
>>>> David,
>>>>
>>>> Can you also send a GC log from a run where there
>>>> is not a problem? As I understand it, that would
>>>> be a 32bit run.
>>>>
>>>> Jon
>>>>
>>>> David Sitsky wrote On 02/24/09 16:04,:
>>>>
>>>>> Jon Masamitsu wrote:
>>>>>
>>>>>> Jon Masamitsu wrote On 02/23/09 17:20,:
>>>>>>
>>>>>>
>>>>>>> ...
>>>>>>>
>>>>>>> Increase the heap by 30%. Also increase the the perm gen size
>>>>>>> (-XX:MaxPermSize=<nn>).
>>>>>>>
>>>>>>> Please use -XX:+PrintGCDetails -XX:+PrintGCTimeStamps when
>>>> gathering the
>>>>>>> GC logs.
>>>>>>> If you've already gathering some, send those but in future runs,
>>>> use the
>>>>>>> above.
>>>>>>>
>>>>> Here is a sample of output from a stuck process. You can see its
>>>> doing
>>>>> a full GC about every 3 seconds, and it seems as if there is little
>
>> progress..
>>>>> Please let me know if you need more information.
>>>>>
>>>>> Cheers,
>>>>> David
>>>>>
>>>>> 62402.320: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8063178 secs] [Times: user=2.81
>
>> sys=0.00, real=2.81 secs]
>>>>> 62405.128: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8029997 secs] [Times: user=2.79
>
>> sys=0.00, real=2.81 secs]
>>>>> 62407.932: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7917325 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62410.725: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7891387 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62413.515: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7649110 secs] [Times: user=2.76
>
>> sys=0.00, real=2.76 secs]
>>>>> 62416.281: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7803983 secs] [Times: user=2.78
>
>> sys=0.00, real=2.78 secs]
>>>>> 62419.063: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7643979 secs] [Times: user=2.76
>
>> sys=0.00, real=2.76 secs]
>>>>> 62421.828: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8114336 secs] [Times: user=2.81
>
>> sys=0.00, real=2.81 secs]
>>>>> 62424.640: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7964912 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62427.438: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8107278 secs] [Times: user=2.81
>
>> sys=0.00, real=2.81 secs]
>>>>> 62430.249: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 3.2345212 secs] [Times: user=2.84
>
>> sys=0.00, real=3.24 secs]
>>>>> 62433.484: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8341520 secs] [Times: user=2.82
>
>> sys=0.00, real=2.82 secs]
>>>>> 62436.319: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8698768 secs] [Times: user=2.87
>
>> sys=0.00, real=2.87 secs]
>>>>> 62439.190: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9323230 secs] [Times: user=2.90
>
>> sys=0.00, real=2.92 secs]
>>>>> 62442.124: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9644960 secs] [Times: user=2.96
>
>> sys=0.00, real=2.96 secs]
>>>>> 62445.089: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 3.0059221 secs] [Times: user=3.00
>
>> sys=0.00, real=3.00 secs]
>>>>> 62448.095: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9832815 secs] [Times: user=3.00
>
>> sys=0.00, real=2.99 secs]
>>>>> 62451.079: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9587156 secs] [Times: user=2.93
>
>> sys=0.00, real=2.95 secs]
>>>>> 62454.039: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9488345 secs] [Times: user=2.92
>
>> sys=0.00, real=2.95 secs]
>>>>> 62456.988: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8969788 secs] [Times: user=2.90
>
>> sys=0.00, real=2.90 secs]
>>>>> 62459.886: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8794991 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62462.766: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683675K->683675K(699072K)] 781915K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8842411 secs] [Times: user=2.87
>
>> sys=0.00, real=2.89 secs]
>>>>> 62465.651: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683675K(699072K)] 781916K->781915K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8669173 secs] [Times: user=2.85
>
>> sys=0.00, real=2.85 secs]
>>>>> 62468.519: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8664429 secs] [Times: user=2.85
>
>> sys=0.00, real=2.86 secs]
>>>>> 62471.386: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8844494 secs] [Times: user=2.87
>
>> sys=0.00, real=2.89 secs]
>>>>> 62474.271: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8648398 secs] [Times: user=2.87
>
>> sys=0.00, real=2.87 secs]
>>>>> 62477.137: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8971068 secs] [Times: user=2.87
>
>> sys=0.00, real=2.90 secs]
>>>>> 62480.034: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8655618 secs] [Times: user=2.86
>
>> sys=0.00, real=2.86 secs]
>>>>> 62482.901: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 3.0366140 secs] [Times: user=2.78
>
>> sys=0.00, real=3.04 secs]
>>>>> 62485.939: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8541753 secs] [Times: user=2.85
>
>> sys=0.00, real=2.85 secs]
>>>>> 62488.794: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8582816 secs] [Times: user=2.86
>
>> sys=0.00, real=2.86 secs]
>>>>> 62491.653: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8673218 secs] [Times: user=2.85
>
>> sys=0.00, real=2.86 secs]
>>>>> 62494.521: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9014120 secs] [Times: user=2.87
>
>> sys=0.00, real=2.90 secs]
>>>>> 62497.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8805843 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62500.305: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8905128 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62503.196: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9052007 secs] [Times: user=2.90
>
>> sys=0.00, real=2.92 secs]
>>>>> 62506.102: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9004575 secs] [Times: user=2.89
>
>> sys=0.00, real=2.90 secs]
>>>>> 62509.003: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9160655 secs] [Times: user=2.90
>
>> sys=0.00, real=2.92 secs]
>>>>> 62511.920: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9013277 secs] [Times: user=2.90
>
>> sys=0.00, real=2.90 secs]
>>>>> 62514.822: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8982061 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62517.721: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8922437 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62520.614: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8873520 secs] [Times: user=2.87
>
>> sys=0.00, real=2.89 secs]
>>>>> 62523.502: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8805296 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62526.383: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8958714 secs] [Times: user=2.85
>
>> sys=0.00, real=2.89 secs]
>>>>> 62529.279: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8735384 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62532.154: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8705676 secs] [Times: user=2.87
>
>> sys=0.00, real=2.87 secs]
>>>>> 62535.025: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8723947 secs] [Times: user=2.85
>
>> sys=0.00, real=2.87 secs]
>>>>> 62537.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8624400 secs] [Times: user=2.86
>
>> sys=0.00, real=2.86 secs]
>>>>> 62540.761: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8245748 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62543.587: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8432269 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62546.432: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8394157 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62549.272: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8471951 secs] [Times: user=2.85
>
>> sys=0.00, real=2.85 secs]
>>>>> 62552.121: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8584107 secs] [Times: user=2.85
>
>> sys=0.00, real=2.86 secs]
>>>>> 62554.981: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683676K->683676K(699072K)] 781916K->781916K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8376807 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62557.820: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8402486 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62560.661: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8482704 secs] [Times: user=2.86
>
>> sys=0.00, real=2.85 secs]
>>>>> 62563.511: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8115973 secs] [Times: user=2.81
>
>> sys=0.00, real=2.81 secs]
>>>>> 62566.324: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8523278 secs] [Times: user=2.85
>
>> sys=0.00, real=2.86 secs]
>>>>> 62569.177: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8128563 secs] [Times: user=2.81
>
>> sys=0.00, real=2.81 secs]
>>>>> 62571.990: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7830644 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62574.774: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8065106 secs] [Times: user=2.79
>
>> sys=0.00, real=2.81 secs]
>>>>> 62577.582: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7892171 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62580.372: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8059306 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62583.179: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8641470 secs] [Times: user=2.82
>
>> sys=0.00, real=2.86 secs]
>>>>> 62586.044: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8421364 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62588.887: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8852699 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62591.773: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9164279 secs] [Times: user=2.90
>
>> sys=0.00, real=2.92 secs]
>>>>> 62594.690: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9450010 secs] [Times: user=2.95
>
>> sys=0.00, real=2.95 secs]
>>>>> 62597.636: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9744636 secs] [Times: user=2.98
>
>> sys=0.00, real=2.98 secs]
>>>>> 62600.611: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9900849 secs] [Times: user=2.99
>
>> sys=0.00, real=3.00 secs]
>>>>> 62603.602: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.6332370 secs] [Times: user=2.62
>
>> sys=0.00, real=2.62 secs]
>>>>> 62606.236: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9801260 secs] [Times: user=2.95
>
>> sys=0.00, real=2.98 secs]
>>>>> 62609.226: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9166374 secs] [Times: user=2.89
>
>> sys=0.00, real=2.92 secs]
>>>>> 62612.150: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9475729 secs] [Times: user=2.95
>
>> sys=0.00, real=2.95 secs]
>>>>> 62615.098: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9328670 secs] [Times: user=2.90
>
>> sys=0.00, real=2.93 secs]
>>>>> 62618.040: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8963825 secs] [Times: user=2.89
>
>> sys=0.00, real=2.90 secs]
>>>>> 62620.937: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8834715 secs] [Times: user=2.89
>
>> sys=0.00, real=2.89 secs]
>>>>> 62623.821: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8800691 secs] [Times: user=2.86
>
>> sys=0.00, real=2.87 secs]
>>>>> 62626.701: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683677K(699072K)] 781918K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8642587 secs] [Times: user=2.87
>
>> sys=0.00, real=2.87 secs]
>>>>> 62629.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683677K->683677K(699072K)] 781917K->781917K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8574615 secs] [Times: user=2.84
>
>> sys=0.00, real=2.86 secs]
>>>>> 62632.424: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8383412 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>> 62635.264: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8409891 secs] [Times: user=2.82
>
>> sys=0.00, real=2.84 secs]
>>>>> 62638.106: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7906216 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62640.898: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7891730 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62643.688: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7892940 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62646.479: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7766807 secs] [Times: user=2.78
>
>> sys=0.00, real=2.78 secs]
>>>>> 62649.257: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7796531 secs] [Times: user=2.78
>
>> sys=0.00, real=2.78 secs]
>>>>> 62652.037: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7687240 secs] [Times: user=2.76
>
>> sys=0.00, real=2.76 secs]
>>>>> 62654.807: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7613769 secs] [Times: user=2.76
>
>> sys=0.00, real=2.76 secs]
>>>>> 62657.570: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7712254 secs] [Times: user=2.78
>
>> sys=0.00, real=2.78 secs]
>>>>> 62660.342: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7968108 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62663.139: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.7924173 secs] [Times: user=2.79
>
>> sys=0.00, real=2.79 secs]
>>>>> 62665.933: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8002912 secs] [Times: user=2.79
>
>> sys=0.00, real=2.81 secs]
>>>>> 62668.736: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8291434 secs] [Times: user=2.82
>
>> sys=0.00, real=2.82 secs]
>>>>> 62671.566: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8527186 secs] [Times: user=2.86
>
>> sys=0.00, real=2.85 secs]
>>>>> 62674.419: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8982825 secs] [Times: user=2.90
>
>> sys=0.00, real=2.90 secs]
>>>>> 62677.318: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9254483 secs] [Times: user=2.93
>
>> sys=0.00, real=2.93 secs]
>>>>> 62680.244: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9707015 secs] [Times: user=2.95
>
>> sys=0.00, real=2.96 secs]
>>>>> 62683.216: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9894145 secs] [Times: user=3.00
>
>> sys=0.00, real=3.00 secs]
>>>>> 62686.206: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9870305 secs] [Times: user=2.98
>
>> sys=0.00, real=2.98 secs]
>>>>> 62689.193: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9884647 secs] [Times: user=2.98
>
>> sys=0.00, real=3.00 secs]
>>>>> 62692.183: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9635276 secs] [Times: user=2.96
>
>> sys=0.00, real=2.96 secs]
>>>>> 62695.147: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9407559 secs] [Times: user=2.93
>
>> sys=0.00, real=2.93 secs]
>>>>> 62698.088: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9299386 secs] [Times: user=2.93
>
>> sys=0.00, real=2.93 secs]
>>>>> 62701.019: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8994903 secs] [Times: user=2.90
>
>> sys=0.00, real=2.90 secs]
>>>>> 62703.919: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9163417 secs] [Times: user=2.92
>
>> sys=0.00, real=2.92 secs]
>>>>> 62706.836: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9216473 secs] [Times: user=2.93
>
>> sys=0.00, real=2.93 secs]
>>>>> 62709.758: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.9052547 secs] [Times: user=2.89
>
>> sys=0.00, real=2.90 secs]
>>>>> 62712.664: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8902824 secs] [Times: user=2.85
>
>> sys=0.00, real=2.89 secs]
>>>>> 62715.555: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8865932 secs] [Times: user=2.87
>
>> sys=0.00, real=2.89 secs]
>>>>> 62718.442: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8605445 secs] [Times: user=2.87
>
>> sys=0.00, real=2.87 secs]
>>>>> 62721.304: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683678K->683678K(699072K)] 781918K->781918K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8662771 secs] [Times: user=2.84
>
>> sys=0.00, real=2.86 secs]
>>>>> 62724.171: [Full GC [PSYoungGen: 98240K->98240K(214720K)]
>> [PSOldGen: 683679K->683679K(699072K)] 781919K->781919K(913792K)
>> [PSPermGen: 49694K->49694K(49984K)], 2.8369076 secs] [Times: user=2.84
>
>> sys=0.00, real=2.84 secs]
>>>>>
>
>
> ------------------------------
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use(a)openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>
>
> End of hotspot-gc-use Digest, Vol 15, Issue 7
> *********************************************
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use(a)openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use(a)openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
1
0
hg: jdk7/hotspot-gc/hotspot: 6760309: G1: update remembered sets during Full GCs
by andrey.petrusenko@sun.com 10 Mar '09
by andrey.petrusenko@sun.com 10 Mar '09
10 Mar '09
Changeset: 87fa6e083d82
Author: apetrusenko
Date: 2009-03-10 00:47 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/87fa6e083d82
6760309: G1: update remembered sets during Full GCs
Reviewed-by: iveresov, tonyp
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
! src/share/vm/gc_implementation/g1/g1RemSet.cpp
! src/share/vm/gc_implementation/g1/g1RemSet.hpp
! src/share/vm/gc_implementation/g1/g1RemSet.inline.hpp
! src/share/vm/gc_implementation/g1/heapRegion.hpp
1
0
Changeset: 0ad1cb407fa1
Author: never
Date: 2009-02-25 10:53 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/0ad1cb407fa1
6805427: adlc compiler may generate incorrect machnode emission code
Reviewed-by: kvn, twisti
! src/share/vm/adlc/formssel.cpp
! src/share/vm/adlc/formssel.hpp
Changeset: 07d449658fc7
Author: never
Date: 2009-02-25 14:36 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/07d449658fc7
6807963: need tool to make sense of LogCompilaton output
Reviewed-by: kvn
+ src/share/tools/LogCompilation/Makefile
+ src/share/tools/LogCompilation/README
+ src/share/tools/LogCompilation/manifest.mf
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/BasicLogEvent.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/CallSite.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Compilation.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Constants.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCleanupReader.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCompilation.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogEvent.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogParser.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/MakeNotEntrantEvent.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Method.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/NMethod.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Phase.java
+ src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/UncommonTrapEvent.java
Changeset: 523ded093c31
Author: kvn
Date: 2009-02-26 14:26 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/523ded093c31
6809798: SafePointScalarObject node placed into incorrect block during GCM
Summary: Replace the control edge of a pinned node before scheduling.
Reviewed-by: never
! src/share/vm/opto/block.cpp
! src/share/vm/opto/block.hpp
! src/share/vm/opto/callnode.cpp
! src/share/vm/opto/callnode.hpp
! src/share/vm/opto/gcm.cpp
! src/share/vm/opto/macro.cpp
Changeset: ed6404fac86b
Author: never
Date: 2009-02-26 16:57 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/ed6404fac86b
6810855: KILL vs. TEMP ordering restrictions are too strong
Reviewed-by: kvn
! src/share/vm/adlc/formssel.cpp
Changeset: dbbe28fc66b5
Author: twisti
Date: 2009-02-27 03:35 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/dbbe28fc66b5
6778669: Patch from Red Hat -- fixes compilation errors
Summary: Some fixes which are required to build on recent GCCs.
Reviewed-by: never, kvn
Contributed-by: langel(a)redhat.com
! make/linux/makefiles/adlc.make
! make/solaris/makefiles/adlc.make
! src/share/vm/adlc/adlc.hpp
! src/share/vm/adlc/adlparse.cpp
! src/share/vm/adlc/archDesc.cpp
! src/share/vm/adlc/dfa.cpp
! src/share/vm/adlc/filebuff.cpp
! src/share/vm/adlc/filebuff.hpp
! src/share/vm/adlc/forms.cpp
! src/share/vm/adlc/forms.hpp
! src/share/vm/adlc/formsopt.cpp
! src/share/vm/adlc/formsopt.hpp
! src/share/vm/adlc/formssel.cpp
! src/share/vm/adlc/formssel.hpp
! src/share/vm/adlc/main.cpp
! src/share/vm/adlc/output_c.cpp
! src/share/vm/adlc/output_h.cpp
! src/share/vm/includeDB_core
! src/share/vm/utilities/vmError.cpp
! src/share/vm/utilities/vmError.hpp
Changeset: ec59443af135
Author: kvn
Date: 2009-02-27 08:34 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/ec59443af135
6811267: Fix for 6809798 broke linux build
Summary: Fix method's declaration.
Reviewed-by: phh, twisti
! src/share/vm/opto/block.hpp
Changeset: 98cb887364d3
Author: twisti
Date: 2009-02-27 13:27 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/98cb887364d3
6810672: Comment typos
Summary: I have collected some typos I have found while looking at the code.
Reviewed-by: kvn, never
! src/cpu/sparc/vm/interp_masm_sparc.cpp
! src/cpu/sparc/vm/nativeInst_sparc.hpp
! src/cpu/sparc/vm/sparc.ad
! src/cpu/sparc/vm/templateTable_sparc.cpp
! src/cpu/x86/vm/c1_LIRGenerator_x86.cpp
! src/cpu/x86/vm/cppInterpreter_x86.cpp
! src/cpu/x86/vm/sharedRuntime_x86_64.cpp
! src/cpu/x86/vm/templateInterpreter_x86_64.cpp
! src/cpu/x86/vm/templateTable_x86_32.cpp
! src/cpu/x86/vm/templateTable_x86_64.cpp
! src/cpu/x86/vm/x86_32.ad
! src/cpu/x86/vm/x86_64.ad
! src/os/linux/launcher/java.c
! src/os/linux/launcher/java_md.h
! src/os/linux/vm/perfMemory_linux.cpp
! src/os/solaris/launcher/java.c
! src/os/solaris/launcher/java_md.h
! src/os/solaris/vm/perfMemory_solaris.cpp
! src/os/windows/vm/perfMemory_windows.cpp
! src/os_cpu/solaris_sparc/vm/os_solaris_sparc.cpp
! src/os_cpu/solaris_x86/vm/os_solaris_x86.cpp
! src/share/tools/MakeDeps/Database.java
! src/share/vm/adlc/Doc/Syntax.doc
! src/share/vm/adlc/adlparse.cpp
! src/share/vm/adlc/dict2.cpp
! src/share/vm/adlc/dict2.hpp
! src/share/vm/adlc/filebuff.cpp
! src/share/vm/adlc/filebuff.hpp
! src/share/vm/adlc/formssel.cpp
! src/share/vm/adlc/formssel.hpp
! src/share/vm/adlc/output_h.cpp
! src/share/vm/asm/assembler.cpp
! src/share/vm/asm/assembler.hpp
! src/share/vm/ci/ciTypeFlow.cpp
! src/share/vm/classfile/symbolTable.cpp
! src/share/vm/code/nmethod.cpp
! src/share/vm/code/nmethod.hpp
! src/share/vm/gc_implementation/concurrentMarkSweep/cmsAdaptiveSizePolicy.hpp
! src/share/vm/gc_implementation/concurrentMarkSweep/cmsGCAdaptivePolicyCounters.hpp
! src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
! src/share/vm/gc_implementation/parallelScavenge/cardTableExtension.cpp
! src/share/vm/gc_implementation/parallelScavenge/objectStartArray.hpp
! src/share/vm/gc_implementation/parallelScavenge/prefetchQueue.hpp
! src/share/vm/gc_implementation/shared/mutableNUMASpace.cpp
! src/share/vm/interpreter/abstractInterpreter.hpp
! src/share/vm/interpreter/bytecodeInterpreter.cpp
! src/share/vm/interpreter/bytecodeInterpreter.inline.hpp
! src/share/vm/interpreter/cppInterpreter.hpp
! src/share/vm/interpreter/cppInterpreterGenerator.hpp
! src/share/vm/interpreter/interpreter.hpp
! src/share/vm/interpreter/interpreterGenerator.hpp
! src/share/vm/interpreter/templateInterpreter.hpp
! src/share/vm/interpreter/templateInterpreterGenerator.hpp
! src/share/vm/libadt/dict.cpp
! src/share/vm/libadt/dict.hpp
! src/share/vm/memory/filemap.cpp
! src/share/vm/memory/permGen.hpp
! src/share/vm/oops/generateOopMap.cpp
! src/share/vm/oops/generateOopMap.hpp
! src/share/vm/oops/instanceKlass.cpp
! src/share/vm/oops/klass.cpp
! src/share/vm/oops/klass.hpp
! src/share/vm/oops/methodOop.hpp
! src/share/vm/opto/block.cpp
! src/share/vm/opto/block.hpp
! src/share/vm/opto/buildOopMap.cpp
! src/share/vm/opto/cfgnode.cpp
! src/share/vm/opto/chaitin.cpp
! src/share/vm/opto/chaitin.hpp
! src/share/vm/opto/coalesce.cpp
! src/share/vm/opto/compile.cpp
! src/share/vm/opto/connode.cpp
! src/share/vm/opto/divnode.cpp
! src/share/vm/opto/domgraph.cpp
! src/share/vm/opto/escape.cpp
! src/share/vm/opto/gcm.cpp
! src/share/vm/opto/graphKit.cpp
! src/share/vm/opto/ifg.cpp
! src/share/vm/opto/ifnode.cpp
! src/share/vm/opto/library_call.cpp
! src/share/vm/opto/live.cpp
! src/share/vm/opto/locknode.cpp
! src/share/vm/opto/loopTransform.cpp
! src/share/vm/opto/loopUnswitch.cpp
! src/share/vm/opto/loopnode.cpp
! src/share/vm/opto/loopnode.hpp
! src/share/vm/opto/loopopts.cpp
! src/share/vm/opto/machnode.cpp
! src/share/vm/opto/macro.cpp
! src/share/vm/opto/matcher.cpp
! src/share/vm/opto/memnode.cpp
! src/share/vm/opto/memnode.hpp
! src/share/vm/opto/node.cpp
! src/share/vm/opto/node.hpp
! src/share/vm/opto/output.cpp
! src/share/vm/opto/parse.hpp
! src/share/vm/opto/parse1.cpp
! src/share/vm/opto/parse2.cpp
! src/share/vm/opto/phase.cpp
! src/share/vm/opto/phaseX.cpp
! src/share/vm/opto/postaloc.cpp
! src/share/vm/opto/reg_split.cpp
! src/share/vm/opto/runtime.cpp
! src/share/vm/opto/split_if.cpp
! src/share/vm/opto/superword.cpp
! src/share/vm/opto/superword.hpp
! src/share/vm/opto/type.cpp
! src/share/vm/prims/jvmtiRedefineClasses.cpp
! src/share/vm/runtime/extendedPC.hpp
! src/share/vm/runtime/fprofiler.cpp
! src/share/vm/runtime/frame.cpp
! src/share/vm/runtime/frame.inline.hpp
! src/share/vm/runtime/mutex.hpp
! src/share/vm/runtime/orderAccess.hpp
! src/share/vm/runtime/os.cpp
! src/share/vm/runtime/safepoint.cpp
! src/share/vm/runtime/signature.hpp
! src/share/vm/runtime/threadCritical.hpp
! src/share/vm/utilities/globalDefinitions.hpp
Changeset: 19962e74284f
Author: never
Date: 2009-03-01 20:49 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/19962e74284f
6811384: MacroAssembler::serialize_memory may touch next page on amd64
Reviewed-by: kvn, phh, twisti
! src/cpu/x86/vm/assembler_x86.cpp
Changeset: d8c7fa77a6dc
Author: kvn
Date: 2009-03-03 10:34 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/d8c7fa77a6dc
Merge
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
Changeset: 0386097d43d8
Author: dcubed
Date: 2009-03-02 13:57 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/0386097d43d8
6700114: 3/4 Assertion (_thread->get_interp_only_mode() == 1,"leaving interp only when mode not one")
Summary: Don't create JvmtiThreadState for an exiting JavaThread.
Reviewed-by: coleenp, swamyv
! src/share/vm/prims/jvmtiThreadState.hpp
Changeset: ea20d7ce26b0
Author: dcubed
Date: 2009-03-02 14:00 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/ea20d7ce26b0
6800721: 3/4 JavaThread::jvmti_thread_state() and JvmtiThreadState::state_for() robustness
Summary: Check for NULL return values from jvmti_thread_state() and state_for() and return a JVM TI error code as appropriate.
Reviewed-by: coleenp, swamyv
! src/share/vm/prims/jvmtiEnv.cpp
! src/share/vm/prims/jvmtiEnvBase.cpp
! src/share/vm/prims/jvmtiEventController.cpp
! src/share/vm/prims/jvmtiExport.cpp
! src/share/vm/prims/jvmtiRedefineClasses.cpp
! src/share/vm/prims/jvmtiThreadState.hpp
! src/share/vm/runtime/thread.hpp
Changeset: 70998f2e05ef
Author: dcubed
Date: 2009-03-02 14:03 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/70998f2e05ef
6805864: 4/3 Problem with jvmti->redefineClasses: some methods don't get redefined
Summary: Remove incorrect optimization in klassItable::adjust_method_entries(). Add RedefineClasses() tracing support for obsolete method entry.
Reviewed-by: acorn, swamyv
! src/cpu/sparc/vm/interp_masm_sparc.cpp
! src/cpu/sparc/vm/sharedRuntime_sparc.cpp
! src/cpu/x86/vm/interp_masm_x86_32.cpp
! src/cpu/x86/vm/interp_masm_x86_64.cpp
! src/cpu/x86/vm/sharedRuntime_x86_32.cpp
! src/cpu/x86/vm/sharedRuntime_x86_64.cpp
! src/share/vm/includeDB_core
! src/share/vm/oops/klassVtable.cpp
! src/share/vm/prims/jvmtiRedefineClassesTrace.hpp
! src/share/vm/runtime/sharedRuntime.cpp
! src/share/vm/runtime/sharedRuntime.hpp
Changeset: 2f716c0acb64
Author: dcubed
Date: 2009-03-02 14:05 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/2f716c0acb64
6567360: 3/4 SIGBUS in jvmti RawMonitor magic check for unaligned bad monitor pointer
Summary: Change JvmtiEnvBase::is_valid() and JvmtiRawMonitor::is_valid() to fetch the _magic fields via Bytes::get_native_u[248]().
Reviewed-by: coleenp, swamyv
! src/share/vm/prims/jvmtiEnvBase.cpp
! src/share/vm/prims/jvmtiEnvBase.hpp
! src/share/vm/prims/jvmtiImpl.cpp
! src/share/vm/prims/jvmtiImpl.hpp
Changeset: afa80fa86d22
Author: dcubed
Date: 2009-03-02 14:43 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/afa80fa86d22
Merge
! src/cpu/x86/vm/interp_masm_x86_32.cpp
! src/cpu/x86/vm/interp_masm_x86_64.cpp
! src/cpu/x86/vm/sharedRuntime_x86_32.cpp
! src/cpu/x86/vm/sharedRuntime_x86_64.cpp
! src/share/vm/includeDB_core
! src/share/vm/prims/jvmtiRedefineClasses.cpp
! src/share/vm/runtime/sharedRuntime.cpp
Changeset: 5caef2219893
Author: dcubed
Date: 2009-03-02 16:56 -0700
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/5caef2219893
Merge
! src/share/vm/includeDB_core
Changeset: 3db67f76d308
Author: acorn
Date: 2009-03-05 22:07 -0500
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/3db67f76d308
Merge
! src/cpu/sparc/vm/interp_masm_sparc.cpp
! src/cpu/x86/vm/sharedRuntime_x86_64.cpp
! src/share/vm/includeDB_core
! src/share/vm/prims/jvmtiRedefineClasses.cpp
Changeset: bcedf688d882
Author: tonyp
Date: 2009-03-09 11:32 -0400
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/bcedf688d882
Merge
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
! src/share/vm/runtime/os.cpp
1
0
Changeset: 0db4adb6e914
Author: tonyp
Date: 2009-03-07 11:07 -0500
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/0db4adb6e914
6810698: G1: two small bugs in the sparse remembered sets
Summary: The _expanded flag of the sparse RSets is not reset and this can leave a RSet in an inconsistent state if it is expanded more than once. Also, we should be iterating over the _cur, instead of the _next, sparse table
Reviewed-by: apetrusenko, iveresov
! src/share/vm/gc_implementation/g1/sparsePRT.cpp
! src/share/vm/gc_implementation/g1/sparsePRT.hpp
Changeset: ae1579717a57
Author: tonyp
Date: 2009-03-07 11:07 -0500
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/ae1579717a57
6812428: G1: Error: assert(ret || obj_in_cs(obj),"sanity")
Summary: The length of the fast cset test vector is decided at the beginning of a GC, but more regions can be added during the GC. The simple fix is to set the length of the fast cset test vector to the max.
Reviewed-by: iveresov
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
Changeset: 7ea5ca260b28
Author: tonyp
Date: 2009-03-07 11:07 -0500
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/7ea5ca260b28
6814467: G1: small fixes related to concurrent marking verboseness
Summary: A few small fixes to remove some inconsistencies in the concurrent mark-related verbose GC output.
Reviewed-by: jmasa
! src/share/vm/gc_implementation/g1/concurrentMark.cpp
! src/share/vm/gc_implementation/g1/concurrentMarkThread.cpp
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
1
0
hg: jdk7/hotspot-gc/hotspot: 6720309: G1: don't synchronously update RSet during evacuation pauses; ...
by igor.veresov@sun.com 07 Mar '09
by igor.veresov@sun.com 07 Mar '09
07 Mar '09
Changeset: 4f360ec815ba
Author: iveresov
Date: 2009-03-06 13:50 -0800
URL: http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/4f360ec815ba
6720309: G1: don't synchronously update RSet during evacuation pauses
6720334: G1: don't update RSets of collection set regions during an evacuation pause
Summary: Introduced a deferred update mechanism for delaying the rset updates during the collection pause
Reviewed-by: apetrusenko, tonyp
! src/share/vm/gc_implementation/g1/concurrentG1RefineThread.cpp
! src/share/vm/gc_implementation/g1/dirtyCardQueue.cpp
! src/share/vm/gc_implementation/g1/dirtyCardQueue.hpp
! src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
! src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp
! src/share/vm/gc_implementation/g1/g1RemSet.cpp
! src/share/vm/gc_implementation/g1/g1RemSet.hpp
! src/share/vm/gc_implementation/g1/g1RemSet.inline.hpp
! src/share/vm/gc_implementation/g1/g1_globals.hpp
! src/share/vm/gc_implementation/g1/ptrQueue.cpp
! src/share/vm/gc_implementation/g1/ptrQueue.hpp
! src/share/vm/memory/cardTableModRefBS.cpp
! src/share/vm/memory/cardTableModRefBS.hpp
1
0
Code Review Request: 6814467: G1: small fixes related to concurrent marking verboseness (XXXS)
by Tony Printezis 06 Mar '09
by Tony Printezis 06 Mar '09
06 Mar '09
Hi,
Three tiny fixes that I packaged up together. Webrev is here:
http://cr.openjdk.java.net/~tonyp/6814467/webrev.00/
From the CR:
This CR covers three very small fixes all of which cause some strangeness to the verbose GC output:
a) there's one occurence in concurrentMarkThread.cpp where tty is used, instead of gclog_or_tty, when printing verbose GC output
b) doConcurrentMark() was, for some reason, incorrectly called from checkConcurrentMark (this was causing the marking phase to be incorrectly woken up after a Full GC; no marking actually happened, but marking related verbose GC information was printed which was confusing)
c) some fields of ConcurrentMark (_has_aborted, _restart_for_overflow, _concurrent_marking_in_progress, and _should_gray_objects) were not initialised. In some cases, and in conjuction with b), this was causing the marking thread to output "[GC ocnurrent-mark-restart-for-overflow]" several times a second and was bloating the GC log.
Thanks,
Tony
--
----------------------------------------------------------------------
| Tony Printezis, Staff Engineer | Sun Microsystems Inc. |
| | MS BUR02-311 |
| e-mail: tony.printezis(a)sun.com | 35 Network Drive |
| office: +1 781 442 0998 (x20998) | Burlington, MA01803-0902, USA |
----------------------------------------------------------------------
e-mail client: Thunderbird (Solaris)
1
0