Re: [rvm-research] How to record objects' read/write times
Robin Garner <[email protected]>
| Newsgroups | gmane.comp.java.jikes.rvm.devel |
|---|---|
| Message-ID | <[email protected]> |
On 26/05/15 01:09, 王晨曦 wrote: > Hi,Robin > > Thank you for your response. > I have read this paper[1] and the source code according to your > response just now and understand most them. > but I still have some doubts. Hi Chen Xi, I'm glad things are starting to make more sense. > > On Mon, May 25, 2015 at 1:44 PM, Robin Garner <[email protected]> wrote: >> On 24/05/15 20:16, 王晨曦 wrote: >>> Thanks for Robin and Eliot 's heap! >>> >>> This problem is complex and I don't make it clear. When I make >>> progress ,I will post it here. >>> >>> Now I'm working on some basic problems. And one of these problems is >>> how to confirm the nurser's size.( in GenImmix config ) >> >> By default MMTk's generational plans use a bounded Appel-style nursery >> [1]. At the end of each collection, the nursery size is set to 1/2 the >> available heap size, rounded down to the configured maximum. As the >> mature space grows, the heap size shrinks until a major collection is >> triggered and the nursery grows again. We find this gives the best >> throughput, while the maximum nursery size bounds the time for a nursery GC. >> > > As far as I know, There are there kinds of variables to describe the > nursery's size.( GenImmix config ) > > First kind: > Space.java > > protected final Address start; > protected final Extent extent; > > These variables' value is got from the vmRequest. > And the vmRequest is created in Gen.java > private static final VMRequest vmRequest = USE_DISCONTIGUOUS_NURSERY ? > VMRequest.create() : VMRequest.create(NURSERY_VM_FRACTION, true); > > In production config ,The USE_DISCONTIGUOUS_NURSERY=false; the > NURSERY_VM_FRACTION=0.15f > So, In my opinion ,the size of nursery can't exceed the value of > [start -- start+extent]; No matter what's the command line (option) > is. That's right. These are maximum values that can't be exceeded without editing the source (or properties files) and recompiling. > Second kind: > The value get from the command line (such as the -X:gc:fixedNusery > or the default value) > > In NurserySize.java > boundedNursery.value //Describe the upper bound of the nursery. In pages > fixedNursery.value //Describe the lower bound of the nursery. In pages > (The value is a protected variable in Pagesoption , I just want to > describe the connection clearly) > > As you say ," The nursery size will rounded down to the configured > maximum" , I think the " configured maximum" is the value > :boundedNursery.value > access by the Options.nurserySize.getMaxNursery() Yes, this is right. However, there is no guarantee that a collection won't be triggered before the nursery reaches this maximum size - any space can trigger a GC, and there are other conditions whereby the nursery could trigger a GC. > If there is no command line, In GenImmix ,the Default value of > upper/lower bound is > > public static final int DEFAULT_MIN_NURSERY = (2 << 20) >> > LOG_BYTES_IN_PAGE; //LOG_BYTES_IN_PAGE is 4KB, 12 bits > public static final int DEFAULT_MAX_NURSERY = (32 << 20) >> LOG_BYTES_IN_PAGE; > > These variables describe the actual rang of the nursery size. > > Third kind: > > PageResource.java > > protected int reserved; // nurserySpace.reserved > > This variable describe the exact size used( used + pending size ) by > the nursery. > In my opinion, if the Options.nurserySize.getMaxNursery() < > nurserySpace.reserved ,It will trigger a minor GC; > And the nurserySpace.reserved is 0 in the begin. > > Is these right ? Yes, you are right, but there's more to it. Whether or not the GC will be a minor GC is set at the end of the previous GC, by the line > nextGCFullHeap = (getPagesAvail() < Options.nurserySize.getMinNursery()); in Gen.java. The test in collectionRequired, comparing Options.nurserySize and nurserySpace.reservedPages is an additional test to stop the nursery growing beyond its configured bound. Even if this check fails, the standard tests that apply to growing any space (in Plan#collectionRequired) are still applied. That is, we check whether growing the nursery would make the heap (including copy reserve) exceed the current maximum heap size (either set by the HeapGrowthManager or by the -Xmx flag). This is done by the line > boolean heapFull = getPagesReserved() > getTotalPages(); in Plan#collectionRequired. There's also the check implemented by the method virtualMemoryExhausted. Bottom line, yes, you're right about how it works, but there are several other cases that could cause collection earlier than that. > 1) > So,my first doubt is I can't find which variable to describe the > "the nursery size is set to 1/2 the available heap size ". > I mean the program set which variable to control this ? > May be the nursery size is set as the min of the range > (fixedNursery.value) ,and round to the max size (boundedNursery.value) > when the program is running ? Look at the method Plan#getPagesReserved(). > 2) > My second doubt is that ,In paper[1], the older is alway in the left > of the heap ,and the right of the heap is the from/to space. > And the heap increase in the right. > But In GenImmix ,there are not only 2 space, I can't figure out that > when the heap increase, how the nursery、 mature and other spaces > change ? When I said that we use an Appel-style nursery, we simply use the same method for calculating the *size* of the nursery. The MMTk collectors are considerably more complex than the one described in Appel's paper. > > I guess that only the nursery and mature space can increase with the > heap increase? and when the heap increase ,the nursery is moved to > the left most of the heap. Is these right ? No, all spaces dynamically resize, but they don't change their virtual memory. When we use a nursery in high memory, the base virtual address of the nursery is fixed at build time. When we talk about "resizing" spaces, we simply mean using more or less of the space that has been set aside. There's also the option to use a discontiguous nursery, in which the nursery shares the same pool of 4MB chunks as the other spaces. Discontiguous spaces all share the same virtual address range, which is divided up in 4MB chunks, which are managed by a free-list allocator (see Map.java in org.mmtk.utility.heap if you're interested). > I print the space info (see below), but there is no LOS in GenImmix > ,Is this right ? So the pretenureThreashold control when allocate > the object into mature but not LOS ? Space number 7 below is the LOS space. All MMTk collectors have a LOS space. > 1 Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction > 2 HEAP_START 0x60000000 > 3 AVAILABLE_START 0x65800000 > 4 boot IN 0x60000000->0x6fffffff E 0x10000000 > 5 immortal IND [] > 6 meta ND [] > 7 los ND [] > 8 sanity ND [] > 9 non-moving ND [0x70000000->0x703fffff] > 10 sm-code ND [] > 11 lg-code ND [] > 12 nursery 0x97400000->0x9fffffff F 0.15 > 13 immix ND [] > 14 AVAILABLE_END 0xa0000000 > 15 HEAP_END 0xa0000000 > 16 ================ MMTk Configuration ================ > 17 plan = org.mmtk.plan.generational.immix.GenImmix > 18 HEADER_MARK_BITS = true > > > GenImmix heap space : > > | ---boot ---|---non-moving----|--------mature--------|----nursery--|----> > heap increase ? Where you see "D" in column 2 of the space map, this indicates that the space is discontiguous - these spaces all occupy the space between the lowest "hard coded" space (ie 0x6fffffff) and the nursery (0x97400000). If you print the heap while a program is running (there's an -X:gc:verbose level that does this at every GC, I think), you'll see a list of chunks listed against most of the discontiguous spaces, and you'll get some idea of how these spaces share the virtual address range. > >> This calculation is actually done implicitly in Space#acquire, Plan#poll >> and Gen#collectionRequired. > > This is right! Thank you. > > >> >>> I want to know the nursery(CopySpace)'s exact size when the jikesrvm >>> is running. So I insert some Log.writeln into the source code. >> >> This is actually a difficult question to answer, because we don't >> explicitly calculate the size of a space. What we have is several >> spaces, all competing for the available virtual memory, both by >> allocating it to the VM, and by reserving it for a copy reserve, or for >> fragmentation overheads etc. > > 3) > My third doubt is how the mature and nursery will compete for the > available heap space. > In boundedNursery ,the nursery has a range of size, such as min=2M; max=32M; > at some point ,the nursery size is 16M ,will the mature occupy all the > remaining space and result in the nursery can't increase to 32M? > I think the answer is YES. (Is this right ?) > > In this case, > > In function : > collectionRequired(boolean spaceFull, Space space) // assume the > parameters are (true, this ); In Gen.java > { > int availableNurseryPages = Options.nurserySize.getMaxNursery() - > nurserySpace.reservedPages(); > } OK, if you check Space#acquire, you'll see that it sets spaceFull=true only when allocating fresh pages from the PageResource has failed, which is not the usual case. The usual case is that spaceFull=false. > the Options.nurserySize.getMaxNursery()=32M; the > nurserySpace.reservedPages() <32M ,so the availableNurseryPages>0 ,the > collectionRequired will return false (The value of spaceFull) . Is > this right ? No, look through the remainder of the method. > if (availableNurseryPages <= 0) { > return true; > } As you say, this test fails, so we drop through. > if (virtualMemoryExhausted()) { > return true; > } Check the details of this method (the name of the method isn't quite accurate) - this could potentially cause a minor GC before the nursery becomes full. > return super.collectionRequired(spaceFull, space); So then we fall through to Plan#collectionRequired > boolean stressForceGC = stressTestGCRequired(); > boolean heapFull = getPagesReserved() > getTotalPages(); > > return spaceFull || stressForceGC || heapFull; In cases where we haven't exceeded the maximum nursery size, the 'heapFull' test is what triggers most GCs. This is the intuitive test that evaluates "allocated + copy_reserve < max_size". Have a look at how getPagesReserved() is implemented - this will explain much of the mystery, I think. > but the Address rtn = pr.getNewPages(pagesReserved, pages, zeroed) > will return 0 ( function acquire ) , lead to a minor GC. > Is it right ? As I said above, minor/major GC is determined elsewhere. In Space#acquire, the usual case is covered by > if (allowPoll && VM.activePlan.global().poll(false, this)) { > } The line > Address rtn = pr.getNewPages(pagesReserved, pages, zeroed); only returns zero if none of the common GC triggers apply and yet we still can't allocate, for example the space has exceeded the bounds set in the constructor (the start and extent that you identified above). By setting spaceFull=true in the call to poll(), we force a GC. Note, this code is subtle and hard to understand. It's not something most people want or need to get to the bottom of :) > >> >> The calculation that is performed each time Space#acquire is called is: >> if we satisfy this allocation request, then can we *guarantee* that >> there will there be enough memory to collect the heap next time we make >> a global allocation request, without violating the heap size constraints. >> >> For example, at the end of a collection there may be 64MB of free heap, >> so you could say that at this point in time the nursery is 32MB in size, >> and if all objects are allocated in the nursery then by the next >> collection there would be 32MB of nursery space consumed. On the other >> hand, if (say) a 10MB object was allocated in the Large Object Space, >> then at next collection there would be less than 27MB of objects in the >> nursery space. >> >> As a second example, each thread allocates a local buffer (32K I think) >> of nursery space when it allocates using a BumpPointer, so if 128 >> threads allocate a single 12 byte object and one thread allocates the >> remainder, by the time of the next collection, nearly 4MB of memory will >> be committed but unallocated by the (almost) idle threads, plus 4MB of >> copy reserve that can never be used. >> >> As a third example, in the GenCopy collector, pretenuring objects into >> the mature space will reserve the allocated size plus a 100% copy >> reserve, again subtracting space from the nursery. >> >> And so on. >> >>> >>> The x86_64-linux.properties content is: >>> >>> 13 target.arch=ia32 >>> 14 target.os=Linux >>> 15 target.bootimage.code.address=0x64000000 >>> 16 target.bootimage.data.address=0x60000000 >>> 17 target.bootimage.rmap.address=0x67000000 >>> 18 #target.max-mappable.address=0xb0000000 >>> 19 target.max-mappable.address=0xa0000000 >>> 20 target.address.size=32 >>> 21 target.dll-ext=.so >>> 22 target.dll-prefix=lib >>> 23 target.jni-suffix=${target.dll-ext} >>> 24 target.arch.sse2=full >>> 25 target.arch.hw_fsqrt=true >>> >>> >>> I insert some Log.writeln in the CopyLocal.java >>> >>> public CopyLocal(CopySpace space) { >>> super(space, true); >>> >>> //debug >>> Log.writeln("In CopyLocal"); >>> Log.writeln("heap start:"+space.HEAP_START.toLong()); >>> Log.writeln("heap end:"+space.HEAP_END.toLong()); >>> Log.writeln("heap name:"+space.getName()); >>> Log.writeln("nursery space start:"+space.getStart().toLong()); >>> Log.writeln("nursery space extent:"+space.getExtent().toLong()); >>> } >> >> While you can get away with this in the constructor, you wouldn't be >> able to put this code in any normal method. > > 4） > But this is the only way I know how to debug jikesRVM ,Is there any other way？ I'm not saying you can't put Log.write() and Log.writeln() in your code, you just can't use expressions of the form String+Object. Check what I write below as the correct way to write it. If you're just working on MMTk, you can use the MMTk Harness for debugging, and here you can use any Java code you like, including stepping through code in the eclipse debugger. Check the user guide. http://www.jikesrvm.org/UserGuide/The-MMTk-Test-Harness_91750431.html When I'm working on MMTk, I tend to use the harness until my code works there, then switch to debugging in Jikes RVM. Good luck, Regards, Robin >> >>> >>> I got the output as below: >>> >>> 2 In CopyLocal >>> 3 heap start:1610612736 //0x6000 0000 >>> 4 heap end:2684354560 // 0xA000 0000 >>> 5 heap name:nursery >>> 6 nursery space start:2537553920 //0x9740 0000 >>> 7 nursery space extent:146800640 //0x8c00 0000 >>> >>> >>> The heap size is matching to the config in the x86_64-linux.properties >>> (1G) ; and the nursery size is 15% of the heap (140M), just as the >>> NURSERY_VM_FRACTION = 0.15f; >>> >>> And I know this is just the limit of the heap size and nursery size >>> ,not the exact size when the jikesRVM is running. So I insert some >>> other Log.writeln into the function " public void >>> collectionPhase(short phaseId)" in Gen.java , see below: >>> >>> >>> public void collectionPhase(short phaseId) { //Initialize? every >>> phase need to be initialized ?? >>> >>> if (phaseId == SET_COLLECTION_KIND) { >>> super.collectionPhase(phaseId); >>> gcFullHeap = requiresFullHeapCollection(); // gcFullHeap is a >>> boolean, what's the flag use for ? >>> return; >>> } >>> >>> if (phaseId == PREPARE) { >>> >>> Log.writeln("In Gen.java/PREPARE"); >>> Log.writeln("nursery lowerbound:"+Options.nurserySize.getMinNursery()); >>> Log.writeln("nursery uppperbound"+Options.nurserySize.getMaxNursery()); >> >> I'm not sure how this code is working, because you can't do string >> concatenation in MMTk code, nor can you do the implicit conversion from >> long to String that this expression performs. You need to write this as: >> >> > Log.writeln("In Gen.java/PREPARE"); >> > Log.write("nursery lowerbound: "); >> > Log.writeln(Options.nurserySize.getMinNursery()); >> > Log.write("nursery uppperbound: "); >> > Log.writeln(Options.nurserySize.getMaxNursery()); >> >> >>> >>> >>> When I run : rvm >>> >>> the output is matching to the default config : >>> >>> 2685 In Gen.java/PREPARE >>> 2686 nursery lowerbound:512 // 2MB >>> 2687 nursery uppperbound8192 // 32MB >>> >>> 2085 In Gen.java/CLOSURE >>> 2086 nursery lowerbound:512 >>> 2087 nursery uppperbound8192 >>> >>> 2694 In Gen.java/RELEASE >>> 2695 nursery lowerbound:512 >>> 2696 nursery uppperbound8192 >>> >>> >>> And I know this is only the config of the option ,not the exact >>> nursery size. It's just the upper bound and lower bound. >>> >>> When I run : rvm -X:gc:fixedNursery=10m -jar dacapo-9.12-bach.jar h2 >>> >>> The output is : >>> >>> 1143 In Gen.java/CLOSURE >>> 1144 nursery lowerbound:2560 // 10MB >>> 1145 nursery uppperbound2560 >>> >>> 1110 In Gen.java/RELEASE >>> 1111 nursery lowerbound:2560 >>> 1112 nursery uppperbound2560 >>> >>> Yeah, Now the option of the nursery size is fixed 10MB. >>> >>> My questions are : >>> >>> 1) I want to know how do the default parameters pass to the PagesOption.value ? >> >> -X:gc:printOptions on the command line. Note that options are processed >> left-to-right, and printOptions will show you the value at the given >> point in time. This means that >> >> rvm -X:gc:printOptions -X:gc:boundedNursery=128M -X:gc:printOptions >> >> will show you the values before and after setting the boundedOptions value. >> >>> I insert Log.writln into the NurserySize and FixedNursery 's >>> constructor ,but print nothing ! And just as above, The >>> Options.nurserySize.getMinNursery() output is the default parameters. >>> So I think the object fixedNursery must be built. >> >> The Option objects are created at Build time. You will see the output >> of these in the BootImageWriterOutput.txt file. > > > > I find this all the output in this file, Thank you! > > > >> >>> public NurserySize() { >>> >>> //debug >>> Log.writeln("In NurserySize.java:Init NurserySize"); >>> >>> boundedNursery = new BoundedNursery(); >>> fixedNursery = new FixedNursery(boundedNursery); >>> } >>> >>> >>> public FixedNursery(BoundedNursery boundedNursery) { >>> super(Options.set, "Fixed Nursery", >>> "Fix the minimum and maximum size of the nursery to this value", >>> Plan.DEFAULT_MIN_NURSERY); >>> this.boundedNursery = boundedNursery; >>> >>> //debug >>> Log.writeln("In fixedNursery"); >>> Log.writeln("Plan.DEFAULT_MIN_NURSERY"+Plan.DEFAULT_MIN_NURSERY); >>> Log.writeln("Plan.DEFAULT_MIN_NURSERY"+Plan.DEFAULT_MIN_NURSERY); >>> } >>> >> >> Parsing of options is done in >> org.jikesrvm.mm.mminterface.MemoryManager#processCommandLineArg. You >> can print the values at runtime using -X:gc:printOptions. >> >> You can also set loggingChanges=true in OptionSet >> (org.mmtk.utility.options) to track all changes to option values. >> >>> >>> 2) If I want to know the exact size of the nursery (GenImmix), Where >>> can I insert the Log.writeln ? >> >> See the discussion above - this isn't such a well-defined concept. The >> best you can do is probably to print out the size of nurserySpace during >> the PREPARE phase of collection. >> >> hope this helps, >> >> Robin >> >> [1] Simple Generational Garbage Collection and Fast Allocation. Andrew >> W. Appel. Software--Practice and Experience 19(2):171-183, February 1989. >> > > > Thank you very much!! > ------------------------------------------------------------------------------ One dashboard for servers and applications across Physical-Virtual-Cloud Widest out-of-the-box monitoring support with 50+ applications Performance metrics, stats and reports that give you Actionable Insights Deep dive visibility with transaction tracing using APM Insight. http://ad.doubleclick.net/ddm/clk/290420510;117567292;y _______________________________________________ Jikesrvm-researchers mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/jikesrvm-researchers