March 2009 - hotspot-gc-dev

Re: Heap Size Variations
by Jon Masamitsu 11 Mar '09

11 Mar '09

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

Re: Scalability issues with ParallelOld
by Jon Masamitsu 10 Mar '09

10 Mar '09

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

Re: Scalability issues with ParallelOld
by Y. Srinivas Ramakrishna 10 Mar '09

10 Mar '09

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

Re: Scalability issues with ParallelOld
by Jon Masamitsu 10 Mar '09

10 Mar '09

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

Re: Scalability issues with ParallelOld
by Jon Masamitsu 10 Mar '09

10 Mar '09

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

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

hg: jdk7/hotspot-gc/hotspot: 17 new changesets
by antonios.printezis＠sun.com 09 Mar '09

09 Mar '09

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

hg: jdk7/hotspot-gc/hotspot: 3 new changesets
by antonios.printezis＠sun.com 08 Mar '09

08 Mar '09

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

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

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