First, the most recent versions of java seem to default to CMS instead of serial or throughput (verified on J6; J7 not tested). This is good. Additionally, even the mac J6 can now adjust the size of memory buckets and re-allocate memory as needed. Also good.
But it seems that the adjustment is only upwards. I have yet to see memory released. Second, the adjustment seems to be dominated by startup; how minecraft behaves when loading and initializing mods, before it connects or generates the world is not typical -- yet that seems to be where the memory adjustment changes.
Finally, the allocation seems to operate from "Just grab memory"; as soon as memory is tight, instead of trying to free up memory first, and allocate more if it can't free, it seems to grab more memory first, and try to free up memory second.
Result? If you're on a system with plenty of memory, that's probably not a problem. But if your goal is to keep responsiveness high in a system that needs to keep memory usage under control, you're still going to need to fine-tune things.
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
The Meaning of Life, the Universe, and Everything.
Location:
Austin, TX
Join Date:
7/4/2011
Posts:
63
Member Details
In an attempt to solve a problem with choppiness in single player mode I've been studying up on Java GC (as I believe it to be the culprit). I've been reading through your thread this morning (as well as many other other documents on Java GC) and the information here as been of great help. Thank you for posting the results of all your testing!
Some general thoughts:
JDK 7 has defaulted a lot of old switches to be on by default (e.g. UseCompressedOops) or automatically determined (e.g.ParellelGCThreads and UseSSE). Additionally, some switches such as DisableExplicitGC are inferior to others such as ExplicitGCInvokesConcurrentAndUnloadsClasses (source). Also, some new features/defaults in JDK7 have been retroactively applied to versions of JDK6. I cannot yet find a list of these though. Sorry.
You might find this useful since you are playing around with G1GC: Getting Started with G1 Garbage Collection (Just generally an awesome breakdown of how CMS and G1 garbage collection work and a comparison between the two.)
Currently, I'm compiling a list of arguments to use for myself (single player client), and I will post the results of my logs when testing is completed. I've got 16GB of memory to play with, but I'm starting out my testing under 4GB because I would like to, ideally, keep Minecraft in the 25% range of my total RAM. My hope is that GC is the source of the problem I've been having and these will help resolve that.
Xmx & Xms - I set them the same so my machine doesn't waste processing time managing heap resizing. But why the weird value? In a nutshell, new generation size. I'll explain below
PermSize - Honestly 256MB is a lot for my medium-sized mod pack, well see though when I start testing, but I expect to lower this.
ReservedCodeCacheSize - Defaults at 32MB, trying 512MB because Eyamaz over on the FTB forums (would link his post, but not sure if against rules here), who has very valuable information on this topic btw, said he has yet to see even large mod packs surpass that limit. I expect to lower this after I run some testing due to my much smaller pack size.
NewRatio - At 3 this gave me 1/4 of my heap size (or 640MB) Eden + to Survivor Space + from Survivor Space. I explicitly wanted eden to have 512MB of memory to use. That is why the odd Xmx and Xms values.
Also to note, it probably would have been more correct to have set this explicity with NewSize and MaxNewSize since I'm not letting my heap scale dynamically. I didn't know though whether or not Java would let New scale if I just used NewSize which would require me to use MaxNewSize as well for good measure, and since I could accomplish my task with one parameter change NewRatio, I went with that instead.
SurvivorRatio - At 8 this left each survivor space with (1/8) * 512 = 64MB. With from-SS at 64MB and to-SS at 64MB that gave me 128MB for both survivor spaces. That is 25% of eden and 10% of new generation. This gives me roughly a ±5% margin of error for instruction death, if I'm understand the basics correctly.
TargetSurvivorRatio & MaxTenuringThreshold - Again using Eyamaz's recommendations on these, may tweak later.
Garbage Collection:
UseConcMarkSweepGC - Turns on CMS garbage collection.
CMSParallelRemarkEnabled - Allows GC to use multiple threads for garbage collection.
CMSClassUnloadingEnabled - Allows the unloading of classes, recommended to be turned on when used with the next switch.
ExplicitGCInvokesConcurrentAndUnloadsClasses - This is recommended to be used in place of DisableExplicitGC. Basically, instead of entirely disabling the code from being able to explicitly call a complete garbage collection cycle, it instead intercepts it and lets CMS handle the garbage collection, which should be a minor concurrent cycle instead.
UseParNewGC - ParNew is a parallel new generation garbage collector that is able to run in conjunction with CMS (not to be confused with UseParallelGC which can lead to crashes when used with CMS.)
BindGCTaskThreadToCPUs - Another great tip from Eyamaz! It dynamically determines how many core to use for garbage collection threads so they do not overlap and compete when statically defined. This can replace ParallelGCThreads; which will already auto determine if your CPU has <8 cores and if so assigns a number of cores based on a formula. Why bother with all that if we can let java incrementally spread out our threads?
UseCMSInitiatingOccupancyOnly - Recommended to be turned on when using the following switch. Applies GC calls globally to all instances when on.
CMSInitiatingOccupancyFraction - A percentage. Specifies when CMS garbage collection should start based on how much permanent generation space is used. Again, this article is great for explaining this. Default value is ≈92 or 92%, but that was JDK 6, and it varies upon release.
SoftRefLRUPolicyMSPerMB - Recommended to be set at 0 or causes memory leaks. Specifies delay in milliseconds/MB that soft references should be kept.
GCTimeRatio - Basically tells the JVM that I want the application to get 19x the CPU time as the GC, or rather that 5% of the time the GC gets to run.
MaxGCPauseMillis - Represented in milliseconds. This is warned against changing, as values too low (typically under 100) can lead to instability in the JVM. I decided not to use this since it will dynamically change your heap size to try and stay within this parameter. While now able to apply to CMS, it was originally intended to be a G1GC flag because in G1GC you do NOT want to explicitly define a new generation size.
GCPauseIntervalMillis - Again represented in milliseconds and not used for the same reason as above.
UseAdaptiveSizePolicy - Another feature primarily designed for G1GC that can dynamically change heap sizes. I'm avoiding it.
I may test with these parameters though just to see if they actually do override my static new generation size. Will get back to you.
Well anyways, I'm still learning this stuff, please critique any of those at will. I'm very open to discussion. In the meantime I will be starting my test runs and getting my log parameters set up.
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
Eyamaz has a fairly detailed set of compiler flags for J7.
Yep, I'm familiar with his post, I indirectly referenced it a couple of times above. It's great information.
So my first run was a bit....confusing. I won't post that log since I think I had some confounding factors. I did manage to find a fantastic tool for viewing logs though.
{Heap before GC invocations=0 (full 0):
par new generation total 524288K, used 349568K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17106K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:45:29.541-0600: 3.305: [GC2013-12-01T08:45:29.541-0600: 3.305: [ParNew: 349568K->36931K(524288K), 0.0261282 secs] 349568K->36931K(1922432K), 0.0262602 secs] [Times: user=0.05 sys=0.03, real=0.03 secs]
Heap after GC invocations=1 (full 0):
par new generation total 524288K, used 36931K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 21% used [0x0000000798000000, 0x000000079a410d70, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17106K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=1 (full 0):
par new generation total 524288K, used 88506K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 14% used [0x0000000778000000, 0x000000077b25daf8, 0x000000078d560000)
from space 174720K, 21% used [0x0000000798000000, 0x000000079a410d70, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17611K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:45:36.549-0600: 10.312: [GC2013-12-01T08:45:36.549-0600: 10.313: [ParNew: 88506K->33610K(524288K), 0.0188584 secs] 88506K->33610K(1922432K), 0.0189224 secs] [Times: user=0.08 sys=0.02, real=0.02 secs]
Heap after GC invocations=2 (full 0):
par new generation total 524288K, used 33610K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 19% used [0x000000078d560000, 0x000000078f632b00, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17611K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
2013-12-01T08:45:36.568-0600: 10.332: [GC [1 CMS-initial-mark: 0K(1398144K)] 33610K(1922432K), 0.0060681 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2013-12-01T08:45:36.574-0600: 10.338: [CMS-concurrent-mark-start]
2013-12-01T08:45:36.587-0600: 10.351: [CMS-concurrent-mark: 0.009/0.013 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2013-12-01T08:45:36.587-0600: 10.351: [CMS-concurrent-preclean-start]
2013-12-01T08:45:36.590-0600: 10.354: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.590-0600: 10.354: [GC[YG occupancy: 33610 K (524288 K)]2013-12-01T08:45:36.590-0600: 10.354: [Rescan (parallel) , 0.0019702 secs]2013-12-01T08:45:36.592-0600: 10.356: [weak refs processing, 0.0000249 secs]2013-12-01T08:45:36.592-0600: 10.356: [class unloading, 0.0006228 secs]2013-12-01T08:45:36.593-0600: 10.357: [scrub symbol table, 0.0015092 secs]2013-12-01T08:45:36.594-0600: 10.358: [scrub string table, 0.0003804 secs] [1 CMS-remark: 0K(1398144K)] 33610K(1922432K), 0.0048219 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2013-12-01T08:45:36.595-0600: 10.359: [CMS-concurrent-sweep-start]
2013-12-01T08:45:36.598-0600: 10.362: [CMS-concurrent-sweep: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.598-0600: 10.362: [CMS-concurrent-reset-start]
{Heap before GC invocations=2 (full 1):
par new generation total 524288K, used 33610K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 19% used [0x000000078d560000, 0x000000078f632b00, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17608K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:45:36.598-0600: 10.362: [GC2013-12-01T08:45:36.598-0600: 10.362: [ParNew: 33610K->32550K(524288K), 0.0083492 secs] 33610K->32550K(1922432K), 0.0084069 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
Heap after GC invocations=3 (full 1):
par new generation total 524288K, used 32550K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 18% used [0x0000000798000000, 0x0000000799fc9bc0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 17608K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
2013-12-01T08:45:36.615-0600: 10.379: [CMS-concurrent-reset: 0.008/0.017 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2013-12-01T08:45:36.615-0600: 10.379: [GC [1 CMS-initial-mark: 0K(1398144K)] 32550K(1922432K), 0.0053054 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.620-0600: 10.384: [CMS-concurrent-mark-start]
2013-12-01T08:45:36.627-0600: 10.391: [CMS-concurrent-mark: 0.007/0.007 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2013-12-01T08:45:36.627-0600: 10.391: [CMS-concurrent-preclean-start]
2013-12-01T08:45:36.630-0600: 10.394: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.630-0600: 10.394: [GC[YG occupancy: 32550 K (524288 K)]2013-12-01T08:45:36.630-0600: 10.394: [Rescan (parallel) , 0.0017111 secs]2013-12-01T08:45:36.632-0600: 10.396: [weak refs processing, 0.0000259 secs]2013-12-01T08:45:36.632-0600: 10.396: [class unloading, 0.0006184 secs]2013-12-01T08:45:36.633-0600: 10.397: [scrub symbol table, 0.0015904 secs]2013-12-01T08:45:36.634-0600: 10.398: [scrub string table, 0.0003716 secs] [1 CMS-remark: 0K(1398144K)] 32550K(1922432K), 0.0046376 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.635-0600: 10.399: [CMS-concurrent-sweep-start]
2013-12-01T08:45:36.638-0600: 10.402: [CMS-concurrent-sweep: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2013-12-01T08:45:36.638-0600: 10.402: [CMS-concurrent-reset-start]
2013-12-01T08:45:36.640-0600: 10.404: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
{Heap before GC invocations=3 (full 2):
par new generation total 524288K, used 279412K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 70% used [0x0000000778000000, 0x00000007871134a8, 0x000000078d560000)
from space 174720K, 18% used [0x0000000798000000, 0x0000000799fc9bc0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 20738K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:45:38.156-0600: 11.921: [GC2013-12-01T08:45:38.157-0600: 11.921: [ParNew: 279412K->89834K(524288K), 0.0486083 secs] 279412K->89834K(1922432K), 0.0487325 secs] [Times: user=0.17 sys=0.09, real=0.05 secs]
Heap after GC invocations=4 (full 2):
par new generation total 524288K, used 89834K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 51% used [0x000000078d560000, 0x0000000792d1aac8, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 20738K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
2013-12-01T08:45:38.205-0600: 11.970: [GC [1 CMS-initial-mark: 0K(1398144K)] 91032K(1922432K), 0.0206101 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2013-12-01T08:45:38.226-0600: 11.990: [CMS-concurrent-mark-start]
2013-12-01T08:45:38.249-0600: 12.013: [CMS-concurrent-mark: 0.011/0.023 secs] [Times: user=0.06 sys=0.02, real=0.02 secs]
2013-12-01T08:45:38.249-0600: 12.013: [CMS-concurrent-preclean-start]
2013-12-01T08:45:38.252-0600: 12.016: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:38.252-0600: 12.016: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2013-12-01T08:45:43.521-0600: 17.285: [CMS-concurrent-abortable-preclean: 4.474/5.269 secs] [Times: user=11.11 sys=0.27, real=5.27 secs]
2013-12-01T08:45:43.521-0600: 17.285: [GC[YG occupancy: 203199 K (524288 K)]2013-12-01T08:45:43.521-0600: 17.285: [Rescan (parallel) , 0.0125077 secs]2013-12-01T08:45:43.534-0600: 17.298: [weak refs processing, 0.0000293 secs]2013-12-01T08:45:43.534-0600: 17.298: [class unloading, 0.0013630 secs]2013-12-01T08:45:43.535-0600: 17.299: [scrub symbol table, 0.0018216 secs]2013-12-01T08:45:43.537-0600: 17.301: [scrub string table, 0.0003882 secs] [1 CMS-remark: 0K(1398144K)] 203199K(1922432K), 0.0170246 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2013-12-01T08:45:43.538-0600: 17.303: [CMS-concurrent-sweep-start]
2013-12-01T08:45:43.542-0600: 17.306: [CMS-concurrent-sweep: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T08:45:43.542-0600: 17.306: [CMS-concurrent-reset-start]
2013-12-01T08:45:43.545-0600: 17.309: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
{Heap before GC invocations=4 (full 3):
par new generation total 524288K, used 424393K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 95% used [0x0000000778000000, 0x000000078c6b7b58, 0x000000078d560000)
from space 174720K, 51% used [0x000000078d560000, 0x0000000792d1aac8, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 22315K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:45:44.533-0600: 18.297: [GC2013-12-01T08:45:44.533-0600: 18.297: [ParNew: 424393K->126278K(524288K), 0.0454364 secs] 424393K->126278K(1922432K), 0.0455117 secs] [Times: user=0.13 sys=0.11, real=0.05 secs]
Heap after GC invocations=5 (full 3):
par new generation total 524288K, used 126278K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 72% used [0x0000000798000000, 0x000000079fb519e0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 22315K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=5 (full 3):
par new generation total 524288K, used 469277K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 98% used [0x0000000778000000, 0x000000078cef5b58, 0x000000078d560000)
from space 174720K, 72% used [0x0000000798000000, 0x000000079fb519e0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 22732K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:46:09.024-0600: 42.789: [GC2013-12-01T08:46:09.025-0600: 42.789: [ParNew: 469277K->164917K(524288K), 0.0285408 secs] 469277K->164917K(1922432K), 0.0286171 secs] [Times: user=0.09 sys=0.00, real=0.03 secs]
Heap after GC invocations=6 (full 3):
par new generation total 524288K, used 164917K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 94% used [0x000000078d560000, 0x000000079766d5a0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 22732K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=6 (full 3):
par new generation total 524288K, used 514246K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 99% used [0x0000000778000000, 0x000000078d5243f0, 0x000000078d560000)
from space 174720K, 94% used [0x000000078d560000, 0x000000079766d5a0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23025K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:46:39.543-0600: 73.307: [GC2013-12-01T08:46:39.543-0600: 73.307: [ParNew: 514246K->130625K(524288K), 0.0284142 secs] 514246K->130625K(1922432K), 0.0284846 secs] [Times: user=0.17 sys=0.01, real=0.03 secs]
Heap after GC invocations=7 (full 3):
par new generation total 524288K, used 130625K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 74% used [0x0000000798000000, 0x000000079ff90448, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23025K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=7 (full 3):
par new generation total 524288K, used 480193K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 74% used [0x0000000798000000, 0x000000079ff90448, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23159K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:47:22.841-0600: 116.605: [GC2013-12-01T08:47:22.841-0600: 116.605: [ParNew: 480193K->165591K(524288K), 0.0286738 secs] 480193K->165591K(1922432K), 0.0288224 secs] [Times: user=0.19 sys=0.00, real=0.03 secs]
Heap after GC invocations=8 (full 3):
par new generation total 524288K, used 165591K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 94% used [0x000000078d560000, 0x0000000797715f40, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23159K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=8 (full 3):
par new generation total 524288K, used 515159K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 94% used [0x000000078d560000, 0x0000000797715f40, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23195K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:48:00.512-0600: 154.275: [GC2013-12-01T08:48:00.512-0600: 154.275: [ParNew: 515159K->110638K(524288K), 0.0655566 secs] 515159K->139240K(1922432K), 0.0656402 secs] [Times: user=0.26 sys=0.06, real=0.06 secs]
Heap after GC invocations=9 (full 3):
par new generation total 524288K, used 110638K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 63% used [0x0000000798000000, 0x000000079ec0b9d0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 28601K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23195K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=9 (full 3):
par new generation total 524288K, used 460206K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 63% used [0x0000000798000000, 0x000000079ec0b9d0, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 28601K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23211K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:48:38.073-0600: 191.837: [GC2013-12-01T08:48:38.073-0600: 191.837: [ParNew: 460206K->144905K(524288K), 0.0263389 secs] 488808K->174146K(1922432K), 0.0264010 secs] [Times: user=0.16 sys=0.03, real=0.03 secs]
Heap after GC invocations=10 (full 3):
par new generation total 524288K, used 144905K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 82% used [0x000000078d560000, 0x00000007962e25e0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23211K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=10 (full 3):
par new generation total 524288K, used 487289K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 97% used [0x0000000778000000, 0x000000078ce5bf90, 0x000000078d560000)
from space 174720K, 82% used [0x000000078d560000, 0x00000007962e25e0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23298K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:49:20.112-0600: 233.876: [GC2013-12-01T08:49:20.112-0600: 233.876: [ParNew: 487289K->109051K(524288K), 0.0223324 secs] 516530K->138292K(1922432K), 0.0224028 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
Heap after GC invocations=11 (full 3):
par new generation total 524288K, used 109051K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 62% used [0x0000000798000000, 0x000000079ea7ed90, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23298K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=11 (full 3):
par new generation total 524288K, used 458619K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 62% used [0x0000000798000000, 0x000000079ea7ed90, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23332K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:49:38.891-0600: 252.656: [GC2013-12-01T08:49:38.892-0600: 252.656: [ParNew: 458619K->93039K(524288K), 0.0472946 secs] 487860K->151258K(1922432K), 0.0473665 secs] [Times: user=0.13 sys=0.01, real=0.05 secs]
Heap after GC invocations=12 (full 3):
par new generation total 524288K, used 93039K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 53% used [0x000000078d560000, 0x000000079303be08, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 58219K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23332K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=12 (full 3):
par new generation total 524288K, used 442607K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 53% used [0x000000078d560000, 0x000000079303be08, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 58219K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23373K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:50:29.428-0600: 303.191: [GC2013-12-01T08:50:29.428-0600: 303.191: [ParNew: 442607K->65494K(524288K), 0.0149312 secs] 500826K->125070K(1922432K), 0.0150108 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
Heap after GC invocations=13 (full 3):
par new generation total 524288K, used 65494K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079bff5b20, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 59576K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23373K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=13 (full 3):
par new generation total 524288K, used 406726K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 97% used [0x0000000778000000, 0x000000078cd3be10, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079bff5b20, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 59576K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23396K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:51:23.943-0600: 357.707: [GC2013-12-01T08:51:23.943-0600: 357.707: [ParNew: 406726K->61729K(524288K), 0.0149375 secs] 466302K->122509K(1922432K), 0.0150084 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
Heap after GC invocations=14 (full 3):
par new generation total 524288K, used 61729K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 35% used [0x000000078d560000, 0x00000007911a85e8, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 60780K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23396K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=14 (full 3):
par new generation total 524288K, used 406499K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 98% used [0x0000000778000000, 0x000000078d0b0638, 0x000000078d560000)
from space 174720K, 35% used [0x000000078d560000, 0x00000007911a85e8, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 60780K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23416K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:52:26.638-0600: 420.403: [GC2013-12-01T08:52:26.638-0600: 420.403: [ParNew: 406499K->65337K(524288K), 0.0151472 secs] 467279K->127826K(1922432K), 0.0152142 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
Heap after GC invocations=15 (full 3):
par new generation total 524288K, used 65337K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079bfce6b8, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 62488K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23416K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=15 (full 3):
par new generation total 524288K, used 414541K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 99% used [0x0000000778000000, 0x000000078d505138, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079bfce6b8, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 62488K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23426K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:53:09.494-0600: 463.258: [GC2013-12-01T08:53:09.494-0600: 463.258: [ParNew: 414541K->73404K(524288K), 0.0161724 secs] 477030K->136331K(1922432K), 0.0162404 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
Heap after GC invocations=16 (full 3):
par new generation total 524288K, used 73404K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 42% used [0x000000078d560000, 0x0000000791d0f288, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 62926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23426K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=16 (full 3):
par new generation total 524288K, used 421208K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 99% used [0x0000000778000000, 0x000000078d3a6ed0, 0x000000078d560000)
from space 174720K, 42% used [0x000000078d560000, 0x0000000791d0f288, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 62926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23433K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:54:00.353-0600: 514.118: [GC2013-12-01T08:54:00.353-0600: 514.118: [ParNew: 421208K->66043K(524288K), 0.0152797 secs] 484135K->129884K(1922432K), 0.0153565 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
Heap after GC invocations=17 (full 3):
par new generation total 524288K, used 66043K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079c07ee88, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 63840K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23433K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=17 (full 3):
par new generation total 524288K, used 415611K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 37% used [0x0000000798000000, 0x000000079c07ee88, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 63840K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23446K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:54:57.091-0600: 570.855: [GC2013-12-01T08:54:57.091-0600: 570.855: [ParNew: 415611K->74467K(524288K), 0.0156875 secs] 479452K->140369K(1922432K), 0.0157569 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
Heap after GC invocations=18 (full 3):
par new generation total 524288K, used 74467K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 42% used [0x000000078d560000, 0x0000000791e18d58, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 65902K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23446K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=18 (full 3):
par new generation total 524288K, used 424035K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 42% used [0x000000078d560000, 0x0000000791e18d58, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 65902K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:55:32.238-0600: 606.002: [GC2013-12-01T08:55:32.238-0600: 606.002: [ParNew: 424035K->74723K(524288K), 0.0163788 secs] 489937K->143899K(1922432K), 0.0164951 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
Heap after GC invocations=19 (full 3):
par new generation total 524288K, used 74723K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 42% used [0x0000000798000000, 0x000000079c8f8f90, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 69175K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=19 (full 3):
par new generation total 524288K, used 414101K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 97% used [0x0000000778000000, 0x000000078cb6c4b0, 0x000000078d560000)
from space 174720K, 42% used [0x0000000798000000, 0x000000079c8f8f90, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 69175K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23486K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:56:11.711-0600: 645.476: [GC2013-12-01T08:56:11.712-0600: 645.476: [ParNew: 414101K->61299K(524288K), 0.0212192 secs] 483276K->140791K(1922432K), 0.0212921 secs] [Times: user=0.11 sys=0.00, real=0.02 secs]
Heap after GC invocations=20 (full 3):
par new generation total 524288K, used 61299K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 35% used [0x000000078d560000, 0x000000079113cce0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 79492K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23486K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=20 (full 3):
par new generation total 524288K, used 410867K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 35% used [0x000000078d560000, 0x000000079113cce0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 79492K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23497K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:56:48.941-0600: 682.705: [GC2013-12-01T08:56:48.942-0600: 682.705: [ParNew: 410867K->55716K(524288K), 0.0141533 secs] 490359K->139643K(1922432K), 0.0142281 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
Heap after GC invocations=21 (full 3):
par new generation total 524288K, used 55716K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 31% used [0x0000000798000000, 0x000000079b669280, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 83926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23497K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=21 (full 3):
par new generation total 524288K, used 405284K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 31% used [0x0000000798000000, 0x000000079b669280, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 83926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23508K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:57:25.514-0600: 719.278: [GC2013-12-01T08:57:25.514-0600: 719.278: [ParNew: 405284K->56293K(524288K), 0.0168354 secs] 489211K->146297K(1922432K), 0.0169038 secs] [Times: user=0.08 sys=0.02, real=0.02 secs]
Heap after GC invocations=22 (full 3):
par new generation total 524288K, used 56293K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 32% used [0x000000078d560000, 0x0000000790c59688, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 90004K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23508K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=22 (full 3):
par new generation total 524288K, used 405861K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 32% used [0x000000078d560000, 0x0000000790c59688, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 90004K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23511K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:58:14.396-0600: 768.159: [GC2013-12-01T08:58:14.396-0600: 768.159: [ParNew: 405861K->47875K(524288K), 0.0110953 secs] 495865K->138658K(1922432K), 0.0111652 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
Heap after GC invocations=23 (full 3):
par new generation total 524288K, used 47875K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 27% used [0x0000000798000000, 0x000000079aec0f40, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 90782K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23511K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=23 (full 3):
par new generation total 524288K, used 397443K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 27% used [0x0000000798000000, 0x000000079aec0f40, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 90782K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23514K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:59:04.288-0600: 818.052: [GC2013-12-01T08:59:04.288-0600: 818.052: [ParNew: 397443K->42252K(524288K), 0.0119201 secs] 488226K->136675K(1922432K), 0.0120203 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap after GC invocations=24 (full 3):
par new generation total 524288K, used 42252K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 24% used [0x000000078d560000, 0x000000078fea3150, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 94423K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23514K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=24 (full 3):
par new generation total 524288K, used 391820K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 24% used [0x000000078d560000, 0x000000078fea3150, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 94423K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23518K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T08:59:52.865-0600: 866.630: [GC2013-12-01T08:59:52.865-0600: 866.630: [ParNew: 391820K->35320K(524288K), 0.0127541 secs] 486243K->134228K(1922432K), 0.0128148 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap after GC invocations=25 (full 3):
par new generation total 524288K, used 35320K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 20% used [0x0000000798000000, 0x000000079a27e370, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 98907K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23518K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=25 (full 3):
par new generation total 524288K, used 384888K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000)
from space 174720K, 20% used [0x0000000798000000, 0x000000079a27e370, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 98907K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23524K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T09:00:49.695-0600: 923.459: [GC2013-12-01T09:00:49.695-0600: 923.459: [ParNew: 384888K->37745K(524288K), 0.0107404 secs] 483796K->138456K(1922432K), 0.0108054 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap after GC invocations=26 (full 3):
par new generation total 524288K, used 37745K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 21% used [0x000000078d560000, 0x000000078fa3c6d0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 100711K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23524K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
{Heap before GC invocations=26 (full 3):
par new generation total 524288K, used 108700K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 20% used [0x0000000778000000, 0x000000077c54a9e8, 0x000000078d560000)
from space 174720K, 21% used [0x000000078d560000, 0x000000078fa3c6d0, 0x0000000798000000)
to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000)
concurrent mark-sweep generation total 1398144K, used 100711K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23530K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2013-12-01T09:01:02.222-0600: 935.986: [GC2013-12-01T09:01:02.222-0600: 935.986: [ParNew: 108700K->29372K(524288K), 0.0171282 secs] 209411K->136570K(1922432K), 0.0171918 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
Heap after GC invocations=27 (full 3):
par new generation total 524288K, used 29372K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000)
from space 174720K, 16% used [0x0000000798000000, 0x0000000799caf010, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 107198K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23530K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}
2013-12-01T09:01:02.239-0600: 936.003: [GC [1 CMS-initial-mark: 107198K(1398144K)] 140105K(1922432K), 0.0072986 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2013-12-01T09:01:02.247-0600: 936.010: [CMS-concurrent-mark-start]
2013-12-01T09:01:02.281-0600: 936.045: [CMS-concurrent-mark: 0.034/0.034 secs] [Times: user=0.09 sys=0.01, real=0.03 secs]
2013-12-01T09:01:02.281-0600: 936.045: [CMS-concurrent-preclean-start]
2013-12-01T09:01:02.284-0600: 936.048: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2013-12-01T09:01:02.284-0600: 936.048: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2013-12-01T09:01:07.443-0600: 941.208: [CMS-concurrent-abortable-preclean: 2.366/5.160 secs] [Times: user=2.70 sys=0.08, real=5.16 secs]
2013-12-01T09:01:07.444-0600: 941.208: [GC[YG occupancy: 41339 K (524288 K)]2013-12-01T09:01:07.444-0600: 941.208: [Rescan (parallel) , 0.0025202 secs]2013-12-01T09:01:07.446-0600: 941.210: [weak refs processing, 0.0000357 secs]2013-12-01T09:01:07.446-0600: 941.210: [class unloading, 0.0073470 secs]2013-12-01T09:01:07.454-0600: 941.218: [scrub symbol table, 0.0019164 secs]2013-12-01T09:01:07.455-0600: 941.220: [scrub string table, 0.0004835 secs] [1 CMS-remark: 107198K(1398144K)] 148537K(1922432K), 0.0146955 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2013-12-01T09:01:07.458-0600: 941.223: [CMS-concurrent-sweep-start]
2013-12-01T09:01:07.474-0600: 941.238: [CMS-concurrent-sweep: 0.015/0.015 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
2013-12-01T09:01:07.474-0600: 941.238: [CMS-concurrent-reset-start]
2013-12-01T09:01:07.477-0600: 941.241: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation total 524288K, used 47539K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000)
eden space 349568K, 5% used [0x0000000778000000, 0x00000007791bde50, 0x000000078d560000)
from space 174720K, 16% used [0x0000000798000000, 0x0000000799caf010, 0x00000007a2aa0000)
to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000)
concurrent mark-sweep generation total 1398144K, used 101361K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000)
concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
Comparison after installing Forge:
Clean Minecraft:
Number of verboseGC cycles : 0
Number of all Garbage Collections : 27
Number of Full Garbage Collections : 0
Number of Minor Garbage Collections : 27
First Garbage Collection : Sun Dec 1 08:45:29 2013
Last Garbage Collection : Sun Dec 1 09:01:02 2013
Maximum size of New generation : 715,784,192 bytes
Maximum size of Tenured generation : 1,431,699,456 bytes
Maximum size of Permanent generation : 134,217,728 bytes
Overall Garbage Collection overhead : 0.06%
Total time spent in non Garbage Collection : 932 seconds
Maximum Garbage Collection overhead : 20% (Sun Dec 1 08:45:36 2013)
Number of 100% overhead : 0
Total Garbage Collection pause : 0 seconds
Maximum Permanent Generation usage : 24,088,576 bytes ( 17% Sun Dec 1 09:00:49 2013)
Average Permanent Generation usage : 21,424,859 bytes
Maximum Tenured Generation usage : 103,128,064 bytes ( 7% Sun Dec 1 09:00:49 2013 )
Average Tenured Generation usage : 44,918,198 bytes
Maximum New Generation usage : 527,522,816 bytes ( 73% Sun Dec 1 08:48:00 2013 )
Average New Generation usage : 376,757,723 bytes
Java Heap Activity Analysis and Recommendations report
With Forge:
Number of verboseGC cycles : 0
Number of all Garbage Collections : 28
Number of Full Garbage Collections : 0
Number of Minor Garbage Collections : 28
First Garbage Collection : Sun Dec 1 09:35:17 2013
Last Garbage Collection : Sun Dec 1 09:44:59 2013
Maximum size of New generation : 715,784,192 bytes
Maximum size of Tenured generation : 1,431,699,456 bytes
Maximum size of Permanent generation : 134,217,728 bytes
Overall Garbage Collection overhead : 0.14%
Total time spent in non Garbage Collection : 581 seconds
Maximum Garbage Collection overhead : 48% (Sun Dec 1 09:35:28 2013)
Number of 100% overhead : 0
Total Garbage Collection pause : 0 seconds
Maximum Permanent Generation usage : 30,197,760 bytes ( 22% Sun Dec 1 09:44:39 2013)
Average Permanent Generation usage : 25,501,272 bytes
Maximum Tenured Generation usage : 150,500,352 bytes ( 10% Sun Dec 1 09:44:39 2013 )
Average Tenured Generation usage : 72,001,677 bytes
Maximum New Generation usage : 514,890,752 bytes ( 71% Sun Dec 1 09:35:36 2013 )
Average New Generation usage : 382,247,865 bytes
You can see Forge alone doubled my GC overhead, and increased the perm size by about 6MB. But everything else is about the same, slight increases across the board in most fields. Also interesting is that perm space steadily rises in both scenarios, but rises twice as fast with Forge installed.
Well anyways, back to testing. I'm going to be adding in mod packs one at a time and analyzing the results. I'll probably just drop one more memory log here at the end if anyone is interested.
Something to keep in mind: (And yes, I like the logs, I'll pour over them tomorrow probably.)
The behavior of the game during startup has nothing to do with the behavior during play.
Your log includes timestamps; good. Please indicate the time that you finished initializing and began playing.
I'm assuming this is from a single player run; that will make a difference (single player has more overhead than client or server; worse, what the client wants (for primarily rendering) isn't the same as what the server wants (for primarily entity tracking).
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
Your log includes timestamps; good. Please indicate the time that you finished initializing and began playing.
I go right into the world as soon as I start the game, so past the first minute is strictly regular gameplay.
I'm assuming this is from a single player run; that will make a difference (single player has more overhead than client or server; worse, what the client wants (for primarily rendering) isn't the same as what the server wants (for primarily entity tracking).
Yes, since my issue is related to single-player use, that is what my tweaks will be geared toward. I've already made a bunch of changes to the flags, some stuff I was using wrong, some other flags that work better, memory allocation changes, etc. I'll post a quick summary tomorrow, but I need sleep!
Java 7_45, JDK, will run minecraft 164 on the mac. So far, I've loaded up a single player test world with the FTB "Magic Farm" pack, and looked around.
More testing to follow, but with luck this means I can update this for java 7 data moving forward.
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
This is not dead. I have been testing with J7 51. And, I'm testing "gobs of memory" as well (thanks to 16 GB now)
I discovered today something that I have not seen addressed anywhere.
CMS has two major non-concurrent operations, the initial mark, and the remark.
These take time proportional to the size of eden's allocation -- generally, the number of objects in eden.
Under normal circumstances, tossing lots of extra memory at eden gives you better performance -- collections happen less often. And, in normal circumstances, a minor collection (emptying eden) is done before starting a CMS collection.
But in some low memory situations, repeated CMS collections can be done, trying to free up memory, that does not free up. This will cause lots of these two marks to occur without ever doing a minor collection to free up eden. The result is longer and longer pauses and gaps.
Two ways that this can happen:
1. Total tenured space allocated gets close to maximum tenured -- you need to either allocate more memory to java (if possible), or shrink "New".
2. Trying to run with less "free" space (-XX:MinHeapFreeRatio and -XX:MaxHeapFreeRatio) to try to reduce the rate at which java allocates memory for itself.
Both of these are worsened by memory leaks. Most of those that I've seen are client-sided, not server-sided; the worst server-sided leaks I've seen is dimensions being leaked when empty.
On my system, the "too slow" case is at about 60 MB of eden (a pair of marks takes about .15 seconds; a tick's time is .05 seconds). Since survivor space cannot be larger than eden -- and this also affects the tenuring threshold -- mods that generate more than this at a time will be problematic. Note that several mods that do significant worldgen (including new chunk providers such as ATG) can easily consume more than 60 MB during player travel.
For now, it looks like I'm going to recommend eden down in the 40 MB or less range, to avoid swallowing ticks on the garbage collection.
Again: Normally, the Gc's don't have a big problem. The problem is basically a "low on memory", and represents a new worst-case for CMS. In fairness: 1, the parallel collector has done worse for me; 2, as bad as the issue is, you can mitigate it to almost nothing by letting CMS do "precleanings" (the default is to pre-clean; during a preclean, CMS spends up to 5 seconds to try to quickly recover some easy to identify free memory, and a 0.07 pause followed by 5 seconds of no pause won't be noticed. However, pre-cleans are generally just a waste of CPU for minecraft; I've rarely seen them free up anything.); and 3, the only situations where it really is "fatal"/"harmful" is when you don't have spare CPU's for the garbage collection.
In other words, 1 or 2 CPU systems, with low amounts of memory, are the systems that will be most hurt by this and need additional tuning for this sort of worst-case behavior.
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
-
View User Profile
-
View Posts
-
Send Message
Curse PremiumFirst, the most recent versions of java seem to default to CMS instead of serial or throughput (verified on J6; J7 not tested). This is good. Additionally, even the mac J6 can now adjust the size of memory buckets and re-allocate memory as needed. Also good.
But it seems that the adjustment is only upwards. I have yet to see memory released. Second, the adjustment seems to be dominated by startup; how minecraft behaves when loading and initializing mods, before it connects or generates the world is not typical -- yet that seems to be where the memory adjustment changes.
Finally, the allocation seems to operate from "Just grab memory"; as soon as memory is tight, instead of trying to free up memory first, and allocate more if it can't free, it seems to grab more memory first, and try to free up memory second.
Result? If you're on a system with plenty of memory, that's probably not a problem. But if your goal is to keep responsiveness high in a system that needs to keep memory usage under control, you're still going to need to fine-tune things.
* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
Some general thoughts:
JDK 7 has defaulted a lot of old switches to be on by default (e.g. UseCompressedOops) or automatically determined (e.g. ParellelGCThreads and UseSSE). Additionally, some switches such as DisableExplicitGC are inferior to others such as ExplicitGCInvokesConcurrentAndUnloadsClasses (source). Also, some new features/defaults in JDK7 have been retroactively applied to versions of JDK6. I cannot yet find a list of these though.
You might find this useful since you are playing around with G1GC:
Getting Started with G1 Garbage Collection (Just generally an awesome breakdown of how CMS and G1 garbage collection work and a comparison between the two.)
Some good resources for JDK 7:
Java Virtual Machine Enhancements in JDK7
Update Release Notes.
Garbage Collector Ergonomics
Some good resources on JDK 6:
Java GC tuning in Java SE 6 by Oracle (Of course, you have to be aware of the changes made in JDK7 if you are using it instead of 6, and adapt accordingly.)
Default Values for Java SE 6
Currently, I'm compiling a list of arguments to use for myself (single player client), and I will post the results of my logs when testing is completed. I've got 16GB of memory to play with, but I'm starting out my testing under 4GB because I would like to, ideally, keep Minecraft in the 25% range of my total RAM. My hope is that GC is the source of the problem I've been having and these will help resolve that.
This is what I have so far:
My Reasoning...
Memory:
- Xmx & Xms - I set them the same so my machine doesn't waste processing time managing heap resizing. But why the weird value? In a nutshell, new generation size. I'll explain below
- PermSize - Honestly 256MB is a lot for my medium-sized mod pack, well see though when I start testing, but I expect to lower this.
- ReservedCodeCacheSize - Defaults at 32MB, trying 512MB because Eyamaz over on the FTB forums (would link his post, but not sure if against rules here), who has very valuable information on this topic btw, said he has yet to see even large mod packs surpass that limit. I expect to lower this after I run some testing due to my much smaller pack size.
- NewRatio - At 3 this gave me 1/4 of my heap size (or 640MB) Eden + to Survivor Space + from Survivor Space. I explicitly wanted eden to have 512MB of memory to use. That is why the odd Xmx and Xms values.
Also to note, it probably would have been more correct to have set this explicity with NewSize and MaxNewSize since I'm not letting my heap scale dynamically. I didn't know though whether or not Java would let New scale if I just used NewSize which would require me to use MaxNewSize as well for good measure, and since I could accomplish my task with one parameter change NewRatio, I went with that instead. - SurvivorRatio - At 8 this left each survivor space with (1/8) * 512 = 64MB. With from-SS at 64MB and to-SS at 64MB that gave me 128MB for both survivor spaces. That is 25% of eden and 10% of new generation. This gives me roughly a ±5% margin of error for instruction death, if I'm understand the basics correctly.
- TargetSurvivorRatio & MaxTenuringThreshold - Again using Eyamaz's recommendations on these, may tweak later.
Garbage Collection:- GCPauseIntervalMillis - Again represented in milliseconds and not used for the same reason as above.
- UseAdaptiveSizePolicy - Another feature primarily designed for G1GC that can dynamically change heap sizes. I'm avoiding it.
I may test with these parameters though just to see if they actually do override my static new generation size. Will get back to you.Well anyways, I'm still learning this stuff, please critique any of those at will. I'm very open to discussion. In the meantime I will be starting my test runs and getting my log parameters set up.
-
View User Profile
-
View Posts
-
Send Message
Curse PremiumEyamaz has a fairly detailed set of compiler flags for J7.
* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
Yep, I'm familiar with his post, I indirectly referenced it a couple of times above.
So my first run was a bit....confusing. I won't post that log since I think I had some confounding factors. I did manage to find a fantastic tool for viewing logs though.
Java Arguments:
I've tweaked these some to make it easier to read the logs.
Baseline GC Log:
{Heap before GC invocations=0 (full 0): par new generation total 524288K, used 349568K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17106K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:45:29.541-0600: 3.305: [GC2013-12-01T08:45:29.541-0600: 3.305: [ParNew: 349568K->36931K(524288K), 0.0261282 secs] 349568K->36931K(1922432K), 0.0262602 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] Heap after GC invocations=1 (full 0): par new generation total 524288K, used 36931K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 21% used [0x0000000798000000, 0x000000079a410d70, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17106K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=1 (full 0): par new generation total 524288K, used 88506K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 14% used [0x0000000778000000, 0x000000077b25daf8, 0x000000078d560000) from space 174720K, 21% used [0x0000000798000000, 0x000000079a410d70, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17611K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:45:36.549-0600: 10.312: [GC2013-12-01T08:45:36.549-0600: 10.313: [ParNew: 88506K->33610K(524288K), 0.0188584 secs] 88506K->33610K(1922432K), 0.0189224 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] Heap after GC invocations=2 (full 0): par new generation total 524288K, used 33610K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 19% used [0x000000078d560000, 0x000000078f632b00, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17611K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } 2013-12-01T08:45:36.568-0600: 10.332: [GC [1 CMS-initial-mark: 0K(1398144K)] 33610K(1922432K), 0.0060681 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2013-12-01T08:45:36.574-0600: 10.338: [CMS-concurrent-mark-start] 2013-12-01T08:45:36.587-0600: 10.351: [CMS-concurrent-mark: 0.009/0.013 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 2013-12-01T08:45:36.587-0600: 10.351: [CMS-concurrent-preclean-start] 2013-12-01T08:45:36.590-0600: 10.354: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.590-0600: 10.354: [GC[YG occupancy: 33610 K (524288 K)]2013-12-01T08:45:36.590-0600: 10.354: [Rescan (parallel) , 0.0019702 secs]2013-12-01T08:45:36.592-0600: 10.356: [weak refs processing, 0.0000249 secs]2013-12-01T08:45:36.592-0600: 10.356: [class unloading, 0.0006228 secs]2013-12-01T08:45:36.593-0600: 10.357: [scrub symbol table, 0.0015092 secs]2013-12-01T08:45:36.594-0600: 10.358: [scrub string table, 0.0003804 secs] [1 CMS-remark: 0K(1398144K)] 33610K(1922432K), 0.0048219 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2013-12-01T08:45:36.595-0600: 10.359: [CMS-concurrent-sweep-start] 2013-12-01T08:45:36.598-0600: 10.362: [CMS-concurrent-sweep: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.598-0600: 10.362: [CMS-concurrent-reset-start] {Heap before GC invocations=2 (full 1): par new generation total 524288K, used 33610K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 19% used [0x000000078d560000, 0x000000078f632b00, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17608K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:45:36.598-0600: 10.362: [GC2013-12-01T08:45:36.598-0600: 10.362: [ParNew: 33610K->32550K(524288K), 0.0083492 secs] 33610K->32550K(1922432K), 0.0084069 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] Heap after GC invocations=3 (full 1): par new generation total 524288K, used 32550K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 18% used [0x0000000798000000, 0x0000000799fc9bc0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 17608K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } 2013-12-01T08:45:36.615-0600: 10.379: [CMS-concurrent-reset: 0.008/0.017 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2013-12-01T08:45:36.615-0600: 10.379: [GC [1 CMS-initial-mark: 0K(1398144K)] 32550K(1922432K), 0.0053054 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.620-0600: 10.384: [CMS-concurrent-mark-start] 2013-12-01T08:45:36.627-0600: 10.391: [CMS-concurrent-mark: 0.007/0.007 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2013-12-01T08:45:36.627-0600: 10.391: [CMS-concurrent-preclean-start] 2013-12-01T08:45:36.630-0600: 10.394: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.630-0600: 10.394: [GC[YG occupancy: 32550 K (524288 K)]2013-12-01T08:45:36.630-0600: 10.394: [Rescan (parallel) , 0.0017111 secs]2013-12-01T08:45:36.632-0600: 10.396: [weak refs processing, 0.0000259 secs]2013-12-01T08:45:36.632-0600: 10.396: [class unloading, 0.0006184 secs]2013-12-01T08:45:36.633-0600: 10.397: [scrub symbol table, 0.0015904 secs]2013-12-01T08:45:36.634-0600: 10.398: [scrub string table, 0.0003716 secs] [1 CMS-remark: 0K(1398144K)] 32550K(1922432K), 0.0046376 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.635-0600: 10.399: [CMS-concurrent-sweep-start] 2013-12-01T08:45:36.638-0600: 10.402: [CMS-concurrent-sweep: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2013-12-01T08:45:36.638-0600: 10.402: [CMS-concurrent-reset-start] 2013-12-01T08:45:36.640-0600: 10.404: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] {Heap before GC invocations=3 (full 2): par new generation total 524288K, used 279412K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 70% used [0x0000000778000000, 0x00000007871134a8, 0x000000078d560000) from space 174720K, 18% used [0x0000000798000000, 0x0000000799fc9bc0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 20738K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:45:38.156-0600: 11.921: [GC2013-12-01T08:45:38.157-0600: 11.921: [ParNew: 279412K->89834K(524288K), 0.0486083 secs] 279412K->89834K(1922432K), 0.0487325 secs] [Times: user=0.17 sys=0.09, real=0.05 secs] Heap after GC invocations=4 (full 2): par new generation total 524288K, used 89834K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 51% used [0x000000078d560000, 0x0000000792d1aac8, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 20738K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } 2013-12-01T08:45:38.205-0600: 11.970: [GC [1 CMS-initial-mark: 0K(1398144K)] 91032K(1922432K), 0.0206101 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 2013-12-01T08:45:38.226-0600: 11.990: [CMS-concurrent-mark-start] 2013-12-01T08:45:38.249-0600: 12.013: [CMS-concurrent-mark: 0.011/0.023 secs] [Times: user=0.06 sys=0.02, real=0.02 secs] 2013-12-01T08:45:38.249-0600: 12.013: [CMS-concurrent-preclean-start] 2013-12-01T08:45:38.252-0600: 12.016: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:38.252-0600: 12.016: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 2013-12-01T08:45:43.521-0600: 17.285: [CMS-concurrent-abortable-preclean: 4.474/5.269 secs] [Times: user=11.11 sys=0.27, real=5.27 secs] 2013-12-01T08:45:43.521-0600: 17.285: [GC[YG occupancy: 203199 K (524288 K)]2013-12-01T08:45:43.521-0600: 17.285: [Rescan (parallel) , 0.0125077 secs]2013-12-01T08:45:43.534-0600: 17.298: [weak refs processing, 0.0000293 secs]2013-12-01T08:45:43.534-0600: 17.298: [class unloading, 0.0013630 secs]2013-12-01T08:45:43.535-0600: 17.299: [scrub symbol table, 0.0018216 secs]2013-12-01T08:45:43.537-0600: 17.301: [scrub string table, 0.0003882 secs] [1 CMS-remark: 0K(1398144K)] 203199K(1922432K), 0.0170246 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 2013-12-01T08:45:43.538-0600: 17.303: [CMS-concurrent-sweep-start] 2013-12-01T08:45:43.542-0600: 17.306: [CMS-concurrent-sweep: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T08:45:43.542-0600: 17.306: [CMS-concurrent-reset-start] 2013-12-01T08:45:43.545-0600: 17.309: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] {Heap before GC invocations=4 (full 3): par new generation total 524288K, used 424393K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 95% used [0x0000000778000000, 0x000000078c6b7b58, 0x000000078d560000) from space 174720K, 51% used [0x000000078d560000, 0x0000000792d1aac8, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 22315K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:45:44.533-0600: 18.297: [GC2013-12-01T08:45:44.533-0600: 18.297: [ParNew: 424393K->126278K(524288K), 0.0454364 secs] 424393K->126278K(1922432K), 0.0455117 secs] [Times: user=0.13 sys=0.11, real=0.05 secs] Heap after GC invocations=5 (full 3): par new generation total 524288K, used 126278K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 72% used [0x0000000798000000, 0x000000079fb519e0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 22315K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=5 (full 3): par new generation total 524288K, used 469277K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 98% used [0x0000000778000000, 0x000000078cef5b58, 0x000000078d560000) from space 174720K, 72% used [0x0000000798000000, 0x000000079fb519e0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 22732K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:46:09.024-0600: 42.789: [GC2013-12-01T08:46:09.025-0600: 42.789: [ParNew: 469277K->164917K(524288K), 0.0285408 secs] 469277K->164917K(1922432K), 0.0286171 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] Heap after GC invocations=6 (full 3): par new generation total 524288K, used 164917K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 94% used [0x000000078d560000, 0x000000079766d5a0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 22732K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=6 (full 3): par new generation total 524288K, used 514246K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 99% used [0x0000000778000000, 0x000000078d5243f0, 0x000000078d560000) from space 174720K, 94% used [0x000000078d560000, 0x000000079766d5a0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23025K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:46:39.543-0600: 73.307: [GC2013-12-01T08:46:39.543-0600: 73.307: [ParNew: 514246K->130625K(524288K), 0.0284142 secs] 514246K->130625K(1922432K), 0.0284846 secs] [Times: user=0.17 sys=0.01, real=0.03 secs] Heap after GC invocations=7 (full 3): par new generation total 524288K, used 130625K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 74% used [0x0000000798000000, 0x000000079ff90448, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23025K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=7 (full 3): par new generation total 524288K, used 480193K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 74% used [0x0000000798000000, 0x000000079ff90448, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23159K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:47:22.841-0600: 116.605: [GC2013-12-01T08:47:22.841-0600: 116.605: [ParNew: 480193K->165591K(524288K), 0.0286738 secs] 480193K->165591K(1922432K), 0.0288224 secs] [Times: user=0.19 sys=0.00, real=0.03 secs] Heap after GC invocations=8 (full 3): par new generation total 524288K, used 165591K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 94% used [0x000000078d560000, 0x0000000797715f40, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23159K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=8 (full 3): par new generation total 524288K, used 515159K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 94% used [0x000000078d560000, 0x0000000797715f40, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 0K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23195K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:48:00.512-0600: 154.275: [GC2013-12-01T08:48:00.512-0600: 154.275: [ParNew: 515159K->110638K(524288K), 0.0655566 secs] 515159K->139240K(1922432K), 0.0656402 secs] [Times: user=0.26 sys=0.06, real=0.06 secs] Heap after GC invocations=9 (full 3): par new generation total 524288K, used 110638K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 63% used [0x0000000798000000, 0x000000079ec0b9d0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 28601K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23195K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=9 (full 3): par new generation total 524288K, used 460206K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 63% used [0x0000000798000000, 0x000000079ec0b9d0, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 28601K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23211K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:48:38.073-0600: 191.837: [GC2013-12-01T08:48:38.073-0600: 191.837: [ParNew: 460206K->144905K(524288K), 0.0263389 secs] 488808K->174146K(1922432K), 0.0264010 secs] [Times: user=0.16 sys=0.03, real=0.03 secs] Heap after GC invocations=10 (full 3): par new generation total 524288K, used 144905K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 82% used [0x000000078d560000, 0x00000007962e25e0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23211K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=10 (full 3): par new generation total 524288K, used 487289K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 97% used [0x0000000778000000, 0x000000078ce5bf90, 0x000000078d560000) from space 174720K, 82% used [0x000000078d560000, 0x00000007962e25e0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23298K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:49:20.112-0600: 233.876: [GC2013-12-01T08:49:20.112-0600: 233.876: [ParNew: 487289K->109051K(524288K), 0.0223324 secs] 516530K->138292K(1922432K), 0.0224028 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] Heap after GC invocations=11 (full 3): par new generation total 524288K, used 109051K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 62% used [0x0000000798000000, 0x000000079ea7ed90, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23298K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=11 (full 3): par new generation total 524288K, used 458619K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 62% used [0x0000000798000000, 0x000000079ea7ed90, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 29240K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23332K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:49:38.891-0600: 252.656: [GC2013-12-01T08:49:38.892-0600: 252.656: [ParNew: 458619K->93039K(524288K), 0.0472946 secs] 487860K->151258K(1922432K), 0.0473665 secs] [Times: user=0.13 sys=0.01, real=0.05 secs] Heap after GC invocations=12 (full 3): par new generation total 524288K, used 93039K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 53% used [0x000000078d560000, 0x000000079303be08, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 58219K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23332K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=12 (full 3): par new generation total 524288K, used 442607K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 53% used [0x000000078d560000, 0x000000079303be08, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 58219K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23373K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:50:29.428-0600: 303.191: [GC2013-12-01T08:50:29.428-0600: 303.191: [ParNew: 442607K->65494K(524288K), 0.0149312 secs] 500826K->125070K(1922432K), 0.0150108 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] Heap after GC invocations=13 (full 3): par new generation total 524288K, used 65494K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079bff5b20, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 59576K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23373K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=13 (full 3): par new generation total 524288K, used 406726K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 97% used [0x0000000778000000, 0x000000078cd3be10, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079bff5b20, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 59576K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23396K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:51:23.943-0600: 357.707: [GC2013-12-01T08:51:23.943-0600: 357.707: [ParNew: 406726K->61729K(524288K), 0.0149375 secs] 466302K->122509K(1922432K), 0.0150084 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] Heap after GC invocations=14 (full 3): par new generation total 524288K, used 61729K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 35% used [0x000000078d560000, 0x00000007911a85e8, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 60780K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23396K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=14 (full 3): par new generation total 524288K, used 406499K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 98% used [0x0000000778000000, 0x000000078d0b0638, 0x000000078d560000) from space 174720K, 35% used [0x000000078d560000, 0x00000007911a85e8, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 60780K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23416K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:52:26.638-0600: 420.403: [GC2013-12-01T08:52:26.638-0600: 420.403: [ParNew: 406499K->65337K(524288K), 0.0151472 secs] 467279K->127826K(1922432K), 0.0152142 secs] [Times: user=0.00 sys=0.00, real=0.02 secs] Heap after GC invocations=15 (full 3): par new generation total 524288K, used 65337K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079bfce6b8, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 62488K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23416K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=15 (full 3): par new generation total 524288K, used 414541K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 99% used [0x0000000778000000, 0x000000078d505138, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079bfce6b8, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 62488K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23426K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:53:09.494-0600: 463.258: [GC2013-12-01T08:53:09.494-0600: 463.258: [ParNew: 414541K->73404K(524288K), 0.0161724 secs] 477030K->136331K(1922432K), 0.0162404 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] Heap after GC invocations=16 (full 3): par new generation total 524288K, used 73404K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 42% used [0x000000078d560000, 0x0000000791d0f288, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 62926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23426K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=16 (full 3): par new generation total 524288K, used 421208K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 99% used [0x0000000778000000, 0x000000078d3a6ed0, 0x000000078d560000) from space 174720K, 42% used [0x000000078d560000, 0x0000000791d0f288, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 62926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23433K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:54:00.353-0600: 514.118: [GC2013-12-01T08:54:00.353-0600: 514.118: [ParNew: 421208K->66043K(524288K), 0.0152797 secs] 484135K->129884K(1922432K), 0.0153565 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] Heap after GC invocations=17 (full 3): par new generation total 524288K, used 66043K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079c07ee88, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 63840K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23433K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=17 (full 3): par new generation total 524288K, used 415611K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 37% used [0x0000000798000000, 0x000000079c07ee88, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 63840K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23446K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:54:57.091-0600: 570.855: [GC2013-12-01T08:54:57.091-0600: 570.855: [ParNew: 415611K->74467K(524288K), 0.0156875 secs] 479452K->140369K(1922432K), 0.0157569 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] Heap after GC invocations=18 (full 3): par new generation total 524288K, used 74467K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 42% used [0x000000078d560000, 0x0000000791e18d58, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 65902K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23446K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=18 (full 3): par new generation total 524288K, used 424035K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 42% used [0x000000078d560000, 0x0000000791e18d58, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 65902K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:55:32.238-0600: 606.002: [GC2013-12-01T08:55:32.238-0600: 606.002: [ParNew: 424035K->74723K(524288K), 0.0163788 secs] 489937K->143899K(1922432K), 0.0164951 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] Heap after GC invocations=19 (full 3): par new generation total 524288K, used 74723K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 42% used [0x0000000798000000, 0x000000079c8f8f90, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 69175K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=19 (full 3): par new generation total 524288K, used 414101K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 97% used [0x0000000778000000, 0x000000078cb6c4b0, 0x000000078d560000) from space 174720K, 42% used [0x0000000798000000, 0x000000079c8f8f90, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 69175K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23486K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:56:11.711-0600: 645.476: [GC2013-12-01T08:56:11.712-0600: 645.476: [ParNew: 414101K->61299K(524288K), 0.0212192 secs] 483276K->140791K(1922432K), 0.0212921 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] Heap after GC invocations=20 (full 3): par new generation total 524288K, used 61299K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 35% used [0x000000078d560000, 0x000000079113cce0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 79492K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23486K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=20 (full 3): par new generation total 524288K, used 410867K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 35% used [0x000000078d560000, 0x000000079113cce0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 79492K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23497K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:56:48.941-0600: 682.705: [GC2013-12-01T08:56:48.942-0600: 682.705: [ParNew: 410867K->55716K(524288K), 0.0141533 secs] 490359K->139643K(1922432K), 0.0142281 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] Heap after GC invocations=21 (full 3): par new generation total 524288K, used 55716K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 31% used [0x0000000798000000, 0x000000079b669280, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 83926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23497K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=21 (full 3): par new generation total 524288K, used 405284K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 31% used [0x0000000798000000, 0x000000079b669280, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 83926K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23508K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:57:25.514-0600: 719.278: [GC2013-12-01T08:57:25.514-0600: 719.278: [ParNew: 405284K->56293K(524288K), 0.0168354 secs] 489211K->146297K(1922432K), 0.0169038 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] Heap after GC invocations=22 (full 3): par new generation total 524288K, used 56293K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 32% used [0x000000078d560000, 0x0000000790c59688, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 90004K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23508K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=22 (full 3): par new generation total 524288K, used 405861K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 32% used [0x000000078d560000, 0x0000000790c59688, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 90004K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23511K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:58:14.396-0600: 768.159: [GC2013-12-01T08:58:14.396-0600: 768.159: [ParNew: 405861K->47875K(524288K), 0.0110953 secs] 495865K->138658K(1922432K), 0.0111652 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] Heap after GC invocations=23 (full 3): par new generation total 524288K, used 47875K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 27% used [0x0000000798000000, 0x000000079aec0f40, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 90782K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23511K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=23 (full 3): par new generation total 524288K, used 397443K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 27% used [0x0000000798000000, 0x000000079aec0f40, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 90782K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23514K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:59:04.288-0600: 818.052: [GC2013-12-01T08:59:04.288-0600: 818.052: [ParNew: 397443K->42252K(524288K), 0.0119201 secs] 488226K->136675K(1922432K), 0.0120203 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] Heap after GC invocations=24 (full 3): par new generation total 524288K, used 42252K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 24% used [0x000000078d560000, 0x000000078fea3150, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 94423K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23514K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=24 (full 3): par new generation total 524288K, used 391820K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 24% used [0x000000078d560000, 0x000000078fea3150, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 94423K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23518K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T08:59:52.865-0600: 866.630: [GC2013-12-01T08:59:52.865-0600: 866.630: [ParNew: 391820K->35320K(524288K), 0.0127541 secs] 486243K->134228K(1922432K), 0.0128148 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] Heap after GC invocations=25 (full 3): par new generation total 524288K, used 35320K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 20% used [0x0000000798000000, 0x000000079a27e370, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 98907K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23518K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=25 (full 3): par new generation total 524288K, used 384888K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 100% used [0x0000000778000000, 0x000000078d560000, 0x000000078d560000) from space 174720K, 20% used [0x0000000798000000, 0x000000079a27e370, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 98907K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23524K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T09:00:49.695-0600: 923.459: [GC2013-12-01T09:00:49.695-0600: 923.459: [ParNew: 384888K->37745K(524288K), 0.0107404 secs] 483796K->138456K(1922432K), 0.0108054 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] Heap after GC invocations=26 (full 3): par new generation total 524288K, used 37745K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 21% used [0x000000078d560000, 0x000000078fa3c6d0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 100711K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23524K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } {Heap before GC invocations=26 (full 3): par new generation total 524288K, used 108700K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 20% used [0x0000000778000000, 0x000000077c54a9e8, 0x000000078d560000) from space 174720K, 21% used [0x000000078d560000, 0x000000078fa3c6d0, 0x0000000798000000) to space 174720K, 0% used [0x0000000798000000, 0x0000000798000000, 0x00000007a2aa0000) concurrent mark-sweep generation total 1398144K, used 100711K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23530K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 2013-12-01T09:01:02.222-0600: 935.986: [GC2013-12-01T09:01:02.222-0600: 935.986: [ParNew: 108700K->29372K(524288K), 0.0171282 secs] 209411K->136570K(1922432K), 0.0171918 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] Heap after GC invocations=27 (full 3): par new generation total 524288K, used 29372K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 0% used [0x0000000778000000, 0x0000000778000000, 0x000000078d560000) from space 174720K, 16% used [0x0000000798000000, 0x0000000799caf010, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 107198K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23530K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) } 2013-12-01T09:01:02.239-0600: 936.003: [GC [1 CMS-initial-mark: 107198K(1398144K)] 140105K(1922432K), 0.0072986 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2013-12-01T09:01:02.247-0600: 936.010: [CMS-concurrent-mark-start] 2013-12-01T09:01:02.281-0600: 936.045: [CMS-concurrent-mark: 0.034/0.034 secs] [Times: user=0.09 sys=0.01, real=0.03 secs] 2013-12-01T09:01:02.281-0600: 936.045: [CMS-concurrent-preclean-start] 2013-12-01T09:01:02.284-0600: 936.048: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2013-12-01T09:01:02.284-0600: 936.048: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 2013-12-01T09:01:07.443-0600: 941.208: [CMS-concurrent-abortable-preclean: 2.366/5.160 secs] [Times: user=2.70 sys=0.08, real=5.16 secs] 2013-12-01T09:01:07.444-0600: 941.208: [GC[YG occupancy: 41339 K (524288 K)]2013-12-01T09:01:07.444-0600: 941.208: [Rescan (parallel) , 0.0025202 secs]2013-12-01T09:01:07.446-0600: 941.210: [weak refs processing, 0.0000357 secs]2013-12-01T09:01:07.446-0600: 941.210: [class unloading, 0.0073470 secs]2013-12-01T09:01:07.454-0600: 941.218: [scrub symbol table, 0.0019164 secs]2013-12-01T09:01:07.455-0600: 941.220: [scrub string table, 0.0004835 secs] [1 CMS-remark: 107198K(1398144K)] 148537K(1922432K), 0.0146955 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2013-12-01T09:01:07.458-0600: 941.223: [CMS-concurrent-sweep-start] 2013-12-01T09:01:07.474-0600: 941.238: [CMS-concurrent-sweep: 0.015/0.015 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 2013-12-01T09:01:07.474-0600: 941.238: [CMS-concurrent-reset-start] 2013-12-01T09:01:07.477-0600: 941.241: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Heap par new generation total 524288K, used 47539K [0x0000000778000000, 0x00000007a2aa0000, 0x00000007a2aa0000) eden space 349568K, 5% used [0x0000000778000000, 0x00000007791bde50, 0x000000078d560000) from space 174720K, 16% used [0x0000000798000000, 0x0000000799caf010, 0x00000007a2aa0000) to space 174720K, 0% used [0x000000078d560000, 0x000000078d560000, 0x0000000798000000) concurrent mark-sweep generation total 1398144K, used 101361K [0x00000007a2aa0000, 0x00000007f8000000, 0x00000007f8000000) concurrent-mark-sweep perm gen total 131072K, used 23458K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)Comparison after installing Forge:
Clean Minecraft:
- Number of verboseGC cycles : 0
- Number of all Garbage Collections : 27
- Number of Full Garbage Collections : 0
- Number of Minor Garbage Collections : 27
- First Garbage Collection : Sun Dec 1 08:45:29 2013
- Last Garbage Collection : Sun Dec 1 09:01:02 2013
- Maximum size of New generation : 715,784,192 bytes
- Maximum size of Tenured generation : 1,431,699,456 bytes
- Maximum size of Permanent generation : 134,217,728 bytes
- Overall Garbage Collection overhead : 0.06%
- Total time spent in non Garbage Collection : 932 seconds
- Maximum Garbage Collection overhead : 20% (Sun Dec 1 08:45:36 2013)
- Number of 100% overhead : 0
- Total Garbage Collection pause : 0 seconds
- Maximum Permanent Generation usage : 24,088,576 bytes ( 17% Sun Dec 1 09:00:49 2013)
- Average Permanent Generation usage : 21,424,859 bytes
- Maximum Tenured Generation usage : 103,128,064 bytes ( 7% Sun Dec 1 09:00:49 2013 )
- Average Tenured Generation usage : 44,918,198 bytes
- Maximum New Generation usage : 527,522,816 bytes ( 73% Sun Dec 1 08:48:00 2013 )
- Average New Generation usage : 376,757,723 bytes
- Java Heap Activity Analysis and Recommendations report
With Forge:Well anyways, back to testing. I'm going to be adding in mod packs one at a time and analyzing the results. I'll probably just drop one more memory log here at the end if anyone is interested.
-
View User Profile
-
View Posts
-
Send Message
Curse PremiumThe behavior of the game during startup has nothing to do with the behavior during play.
Your log includes timestamps; good. Please indicate the time that you finished initializing and began playing.
I'm assuming this is from a single player run; that will make a difference (single player has more overhead than client or server; worse, what the client wants (for primarily rendering) isn't the same as what the server wants (for primarily entity tracking).
* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
I go right into the world as soon as I start the game, so past the first minute is strictly regular gameplay.
Yes, since my issue is related to single-player use, that is what my tweaks will be geared toward. I've already made a bunch of changes to the flags, some stuff I was using wrong, some other flags that work better, memory allocation changes, etc. I'll post a quick summary tomorrow, but I need sleep!
-
View User Profile
-
View Posts
-
Send Message
Curse PremiumJava 7_45, JDK, will run minecraft 164 on the mac. So far, I've loaded up a single player test world with the FTB "Magic Farm" pack, and looked around.
More testing to follow, but with luck this means I can update this for java 7 data moving forward.
* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
-
View User Profile
-
View Posts
-
Send Message
Curse PremiumI discovered today something that I have not seen addressed anywhere.
CMS has two major non-concurrent operations, the initial mark, and the remark.
These take time proportional to the size of eden's allocation -- generally, the number of objects in eden.
Under normal circumstances, tossing lots of extra memory at eden gives you better performance -- collections happen less often. And, in normal circumstances, a minor collection (emptying eden) is done before starting a CMS collection.
But in some low memory situations, repeated CMS collections can be done, trying to free up memory, that does not free up. This will cause lots of these two marks to occur without ever doing a minor collection to free up eden. The result is longer and longer pauses and gaps.
Two ways that this can happen:
1. Total tenured space allocated gets close to maximum tenured -- you need to either allocate more memory to java (if possible), or shrink "New".
2. Trying to run with less "free" space (-XX:MinHeapFreeRatio and -XX:MaxHeapFreeRatio) to try to reduce the rate at which java allocates memory for itself.
Both of these are worsened by memory leaks. Most of those that I've seen are client-sided, not server-sided; the worst server-sided leaks I've seen is dimensions being leaked when empty.
On my system, the "too slow" case is at about 60 MB of eden (a pair of marks takes about .15 seconds; a tick's time is .05 seconds). Since survivor space cannot be larger than eden -- and this also affects the tenuring threshold -- mods that generate more than this at a time will be problematic. Note that several mods that do significant worldgen (including new chunk providers such as ATG) can easily consume more than 60 MB during player travel.
For now, it looks like I'm going to recommend eden down in the 40 MB or less range, to avoid swallowing ticks on the garbage collection.
Again: Normally, the Gc's don't have a big problem. The problem is basically a "low on memory", and represents a new worst-case for CMS. In fairness: 1, the parallel collector has done worse for me; 2, as bad as the issue is, you can mitigate it to almost nothing by letting CMS do "precleanings" (the default is to pre-clean; during a preclean, CMS spends up to 5 seconds to try to quickly recover some easy to identify free memory, and a 0.07 pause followed by 5 seconds of no pause won't be noticed. However, pre-cleans are generally just a waste of CPU for minecraft; I've rarely seen them free up anything.); and 3, the only situations where it really is "fatal"/"harmful" is when you don't have spare CPU's for the garbage collection.
In other words, 1 or 2 CPU systems, with low amounts of memory, are the systems that will be most hurt by this and need additional tuning for this sort of worst-case behavior.
* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?
-
View User Profile
-
View Posts
-
Send Message
Curse Premium* Promoting this week: Captive Minecraft 4, Winter Realm. Aka: Vertical Vanilla Viewing. Clicky!
* My channel with Mystcraft, and general Minecraft Let's Plays: http://www.youtube.com/user/Keybounce.
* See all my video series: http://www.minecraftforum.net/forums/minecraft-editions/minecraft-editions-show-your/2865421-keybounces-list-of-creation-threads
(In regard to a mod that gives realistic animal genetics):
Would you really rather have bees that make diamonds and oil with magical genetic blocks?
... did I really ask that?