RFR(S): 8223575: add subspace transitions to gc+metaspace=info log lines

Wed Jun 5 17:25:58 UTC 2019

Thanks Thomas, still need to get clarification re: adding Twitter copyright
notice to the new files. I’ll report back when I have an answer.

Tony

—————
Tony Printezis | @TonyPrintezis | tprintezis at twitter.com

On June 5, 2019 at 11:58:59 AM, Thomas Stüfe (thomas.stuefe at gmail.com)
wrote:

Hi Tony,

I keep it short, this variant looks good to me. Thanks for taking (most :)
of my suggestions, and thanks for your perseverance!

..Thomas

On Wed, Jun 5, 2019 at 5:16 PM Tony Printezis <tprintezis at twitter.com>
wrote:

> Thomas,
>
> Latest webrev based on (most!) of your suggestions:
>
> http://cr.openjdk.java.net/~tonyp/8223575/webrev.3/
>
> See inline.
>
>
> —————
> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>
>
> On June 5, 2019 at 1:58:17 AM, Thomas Stüfe (thomas.stuefe at gmail.com)
> wrote:
>
> Hi Tony,
>
> looks good overall. Minor nits:
>
> I do not like the getting-values-in-ctor for MetaspaceSizesSnapshot - it
> conflicts with how the rest of the data are queried in
> G1HeapTransition::Data::Data.
>
>
> Not sure why you think it’s different. I just get the values directly from
> MetaspaceUtils the same way G1HeapTransition::Data gets the values from the
> G1 heap:
>
> G1HeapTransition::Data::Data(G1CollectedHeap* g1_heap) {
>   _eden_length = g1_heap->eden_regions_count();
>   _survivor_length = g1_heap->survivor_regions_count();
>   _old_length = g1_heap->old_regions_count();
>   _archive_length = g1_heap->archive_regions_count();
>   _humongous_length = g1_heap->humongous_regions_count();
> }
>
> and also how PreGCValues (in ParallelGC) gets the values from the PS heap:
>
>   PreGCValues(ParallelScavengeHeap* heap) :
>       _heap_used(heap->used()),
>       _young_gen_used(heap->young_gen()->used_in_bytes()),
>       _old_gen_used(heap->old_gen()->used_in_bytes()) { }
>
> The only difference is that in the metaspace case the methods are static
> and in the other two cases the methods are on the heap object.
>
>
>
> One has to examine the ctor for MetaspaceSizesSnapshot to realize that we
> did not just simply forget querying the sizes.
>
>
> Sure, the *_used fields of PreGCValues are explicitly set (and similar for
> G1HeapTransition::Data) whereas _meta_sizes is constructed implicitly. But
> MetaspaceSizesSnapshot is also used outside PreGCValues and
> G1HeapTransition::Data and it behaves the same as those two. So IMHO I
> think it’s OK to leave it as is, as it is consistent with the other two.
> The only difference is that MetaspaceSizesSnapshot is also embedded in the
> other two (but also used stand-alone) and the other two are not embedded
> anywhere else but only used stand-alone.
>
>
>
> I would prefer a dumb structure getting filled by a metaspace function.
> Or, give MetaspaceSizesSnapshot a "::fill()" or
> "::query_with_current_values()" function which can be called explicitly
> from within G1HeapTransition::Data::Data().
>
> This is aesthetics. I leave it up to you resp. wait for the second
> reviewers opinion.
>
> --
>
> MetaspaceSizesSnapshot:
>
> Can you rename all members named "capacity" to "committed"? In Metaspace,
> capacity refers to the sum of in-use chunks and does not contain the free
> chunks.
>
> (capacity = used + free + waste/overhead for in-use chunks. Committed =
> capacity + free chunks + some other small overheads.)
>
>
> I renamed it as capacity (which I think is more generic) so we can set it
> to anything else we want (in case someone is not happy with committed!)
> while keeping code changes to a minimum. But, I changed it to committed (in
> case we want to add reserved in the future).
>
>
>
>
> --
>
> While you are at it, could you please rename
> MetaspaceUtils::print_metaspace_change to
> MetaspaceUtils::log_metaspace_change since print_.. is usually the name of
> printing functions which take an outputStream*. log_.. () is usually used
> for functions printing to UL or EventLog, so that would be a clearer name.
>
>
> Good suggestion, done.
>
>
>
> Also could you please make a small addition to the comment in
> metaspace.hpp:
>
> -   // Print change in used metadata.
> +   // Print change in used metadata (for GC logging).
>
>
> I slightly rephrased the comment.
>
>
>
> --
>
> I am not sure if this needs a CSR and/or a Release Note since we change
> the format of the Metaspace entgc log entries and that may confuse people.
> If it does, I can review the CSR for you and hopefully it goes fast. I wait
> for the second reviewers opinion on this (preferably someone from Oracles
> GC group).
>
>
> I have no idea if a CSR is needed. Was there a CSR for the
> -Xlog:safepoint* changes? I’ll assume one is not needed unless I’m told
> otherwise. ;-)
>
>
> Tony
>
>
>
> Cheers, Thomas
>
> On Tue, Jun 4, 2019 at 9:37 PM Tony Printezis <tprintezis at twitter.com>
> wrote:
>
>> Hi Thomas,
>>
>> Thanks for the suggestions. Here’s a new webrev:
>>
>> http://cr.openjdk.java.net/~tonyp/8223575/webrev.2/
>>
>> I renamed the spaces as discussed, added the before capacity to the
>> output, and use the committed size, instead of the reserved size, for
>> capacity. The output now looks like this:
>>
>> [31.167s][info][gc,metaspace ] GC(27) Metaspace:
>> 2120K(5504K)->2120K(5504K) NonClass: 1898K(4864K)->1898K(4864K) Class:
>> 221K(640K)->221K(640K)
>>
>> One more minor change: MetaspaceUtils::print_metaspace_change(…) now gets
>> the “after” values using a MetaspaceSizesSnapshot object instead of calling
>> methods directly (which I think is a bit nicer).
>>
>> I'd like to add a Twitter copyright to the two new files. But I’m waiting
>> to hear from the “higher ups” about that. I left two TODOs about that in
>> the metaspaceSizesSnapshot.{hpp,cpp} files so I don’t forget. Please ignore
>> those for now… I’ll remove them before pushing.
>>
>> Tony
>>
>> —————
>> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>>
>>
>> On May 15, 2019 at 4:26:17 AM, Thomas Stüfe (thomas.stuefe at gmail.com)
>> wrote:
>>
>> Hi Tony,
>>
>> I combine my answer to both your mails up into this one mail:
>>
>> - I am fine with printing "used" and "committed" and leaving out
>> "reserved".
>> - Choose whatever format you like, I like them all :)
>>
>> more inline:
>>
>> On Wed, May 15, 2019 at 10:15 AM Tony Printezis <tprintezis at twitter.com>
>> wrote:
>>
>>> Thomas,
>>>
>>> Yeah, I’ll update the space names as discussed in the previous e-mail
>>> and rework the size transition format (unless I hear otherwise!).
>>>
>>> Re: I generally use references for const arguments and pointers for
>>> arguments the method modifies (to make it a bit clearer what will be
>>> modified and what it will not).
>>>
>>
>> Yes, I prefer that too.
>>
>>
>>>
>>> Quick related question: I saw that some files seem to have SAP (and also
>>> RedHat?) copyright notices in addition to the usual Oracle ones. So, I can
>>> add a Twitter copyright line for any new files we add?
>>>
>>
>> I usually add SAP copyrights for files I introduce and which have a
>> reasonable large original content made by us.
>>
>>
>>>
>>> I’m on vacation this week and next, so it might be a few days before I
>>> post a new webrev. Thanks again for the comments!
>>>
>>
>> Np. Enjoy your time off.
>>
>> Cheers, Thomas
>>
>>
>>>
>>> Tony
>>>
>>>
>>> —————
>>> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>>>
>>>
>>> On May 13, 2019 at 7:50:44 PM, Thomas Stüfe (thomas.stuefe at gmail.com)
>>> wrote:
>>>
>>> Hi Tony,
>>>
>>> had a look at your second webrev. Seems fine, modulo the discussion
>>> points from my mail from earlier today.
>>>
>>> Small nit, I personally prefer pointers vs references for output
>>> structures, but I leave it up to you whether you want to change it.
>>>
>>> Cheers, Thomas
>>>
>>> On Thu, May 9, 2019 at 10:00 PM Tony Printezis <tprintezis at twitter.com>
>>> wrote:
>>>
>>>> Thomas,
>>>>
>>>> Updated webrev:
>>>>
>>>> http://cr.openjdk.java.net/~tonyp/8223575/webrev.1/
>>>>
>>>> with some of the suggested changes:
>>>>
>>>> * did some renaming
>>>> * created hpp / cpp files for the new class (now called
>>>> MetaspaceSizesSnapshot)
>>>> * moved the formatting macros to globalDefinitions.hpp
>>>>
>>>> Still pending:
>>>>
>>>> * What should we call the spaces?
>>>> * Should we add the before capacity in the output?
>>>>
>>>> (let me know if I missed anything…)
>>>>
>>>> Tony
>>>>
>>>>
>>>> —————
>>>> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>>>>
>>>>
>>>> On May 9, 2019 at 12:38:35 PM, Tony Printezis (tprintezis at twitter.com)
>>>> wrote:
>>>>
>>>> Hi Thomas,
>>>>
>>>> Thanks for the detailed feedback and suggestions. Please see inline….
>>>>
>>>>
>>>> —————
>>>> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>>>>
>>>>
>>>> On May 8, 2019 at 4:07:49 PM, Thomas Stüfe (thomas.stuefe at gmail.com)
>>>> wrote:
>>>>
>>>>
>>>> Hi Tony,
>>>>
>>>> I think this makes sense. I agree, the output as it is now can be
>>>> confusing. Note that users can still be confused since users may simply not
>>>> be aware that the default ClassSpace reserved size is 1G.
>>>>
>>>>
>>>> Yes. What a user wants to size is (what I call - more below) the class
>>>> metadata space. But, in the log, this is hidden in the total size. So, this
>>>> creates confusion. FWIW, the older +PrintHeapAtGC output had the same issue:
>>>>
>>>>  Metaspace       used 5660K, capacity 5996K, committed 6144K, reserved
>>>> 1056768K
>>>>
>>>>   class space    used 630K, capacity 734K, committed 768K, reserved
>>>> 1048576K
>>>>
>>>> It shows the total size and the class space size (which the user might
>>>> not know what it is) but doesn’t explicitly show the space the user
>>>> actually wants to size.
>>>>
>>>> I think we can make it a bit easier for them.
>>>>
>>>>
>>>>
>>>> Can your change break scripts for folks parsing GC logs? I see that you
>>>> only appended content and did not change the existing text, so I guess this
>>>> is okay.
>>>>
>>>>
>>>> Of course the change can break a GC log parsing script, if it assumes
>>>> there’s only one size transition on gc,metaspace lines (but if it just
>>>> parses the size transition and ignores that rest it will still work). But
>>>> is there a hard requirement that we cannot change any log output? That’d be
>>>> unfortunate, IMHO. In fact, the safepoint=info output changed almost
>>>> totally between 11 and now.
>>>>
>>>> 11:
>>>>
>>>> [49.768s][info ][safepoint        ] Entering safepoint region: Cleanup
>>>>
>>>> ...
>>>>
>>>> [49.769s][info ][safepoint        ] Total time for which application
>>>> threads were stopped: 0.0005466 seconds, Stopping threads took: 0.0001931
>>>> seconds
>>>>
>>>> now:
>>>>
>>>> [880.754s][info ][safepoint        ] Safepoint
>>>> "GenCollectForAllocation", Time since last: 990253904 ns, Reaching
>>>> safepoint: 440316 ns, At safepoint: 3761268 ns, Total: 4201584 ns
>>>>
>>>>
>>>>
>>>> ---
>>>>
>>>> Format and naming: Different forms are used in different places. In
>>>> hs-err files, we print "Metaspace" and "Class Space", with the former being
>>>> the total sum and the latter the class space part.
>>>>
>>>> But in other corners, eg. in the jcmd VM.metaspace command, we print
>>>> non-class space and class space and maybe the sum in addition. Usually
>>>> non-class space is called "Non-Class".
>>>>
>>>> I personally would prefer, in this case, the latter names: "Class
>>>> Space" and "Non-Class Space"
>>>>
>>>>
>>>> Here’s another pet-peeve of mine (and I’m probably overthinking this)
>>>> :-) : Users know that the metaspace holds class metadata. So, calling the
>>>> area that actually holds the class metadata “Non-Class Space” and the area
>>>> that holds some internal JVM data structure “Class Space” is
>>>> counter-productive and confusing (IMHO). We don’t have to use the names I
>>>> used. But any chance of coming up with something less confusing?
>>>>
>>>>
>>>>
>>>> ---
>>>>
>>>> Note that for non-class space, reserved size can actually change when
>>>> allocating and releasing metaspace, if VirtualSpaceNodes get purged or
>>>> newly allocated. Hence total reserved size can change too. So we may want
>>>> to print out reserved before and reserved after sizes. I guess that was
>>>> also missing from the output before.
>>>>
>>>>
>>>> I’ll be very happy to add the before capacity to the output. You mean
>>>> something like this, right?
>>>>
>>>> 2300K(4192K)->2100K(4192K)
>>>>
>>>> And we should also add it to the heap size transitions too, as they
>>>> have the same issue (the heap can be resized during a GC). Of course, this
>>>> will definitely require GC log parser changes. :-) But I think the change
>>>> is worthwhile. Any objections?
>>>>
>>>>
>>>>
>>>> ----
>>>>
>>>> Since used = class used + nonclass used, I would simplify
>>>> PreMetaspaceValues to _non_class_used and _class_used and calculate the sum
>>>> on the fly.
>>>>
>>>>
>>>> Yeah, I thought about that. I just decided to just store the total used
>>>> to avoid replicating the logic of how that’s calculated in that class too.
>>>>
>>>>
>>>>
>>>> ---
>>>>
>>>> You added a new dependency to heap.hpp into metaspace.cpp for the
>>>> format string. Is this really necessary? Can you move this define to
>>>> metaspace.cpp?
>>>>
>>>> If not, you need at least add include heap.hpp (did it build this way
>>>> without precompiled headers?)
>>>>
>>>>
>>>> I didn’t try to explicitly compile without precompiled headers. jdk
>>>> submit job was successful. Is that usually evidence enough? If not, I’ll
>>>> need to add the extra step to my workflow.
>>>>
>>>> As I eluded to earlier, if this change is accepted I’m going to suggest
>>>> to also expand the gc,heap output with sub-space information for the young
>>>> gen (eden  / survivors). So I wanted to move the FORMAT macros to somewhere
>>>> that can also be shared by GC files. I was not sure if heap.hpp was the
>>>> best place for them. Maybe I can just put them in globalDefinitions.hpp, as
>>>> there’s already some size formatting utilities there
>>>> (proper_unit_for_byte_size(…), etc.)?
>>>>
>>>>
>>>>
>>>> ----
>>>>
>>>> The following issues are matters of taste, and I leave it up to you
>>>> whether you want to change something:
>>>>
>>>> -> I wince a bit at yet another metaspace-sizes-structure - we have
>>>> already ClassLoaderMetaspaceStatistics and MetaspaceCounters, and maybe
>>>> others. JFR may also do something similar. Would it be possible to reuse
>>>> one of those? (I guess ClassLoaderMetaspaceStatistics is too fine granular
>>>> and too expensive to collect.)
>>>>
>>>>
>>>> I was not aware of the two you mentioned. Aren’t MetaspaceCounters only
>>>> available when UsePerfData is enabled? I’d rather decouple this from
>>>> UsePerfData. ClassLoaderMetaspaceStatistics does seem too fine-grain for
>>>> what I want. And I modeled PreMetaspaceValues on PreGCValues used in
>>>> ParallelGC, as it’s a nice way to package up what’s needed in an object and
>>>> easily re-use it in the few places where it’s needed. The way is done now,
>>>> i.e., just store the metaspace used size and pass it to the print method,
>>>> is a bit ad-hoc (IMHO).
>>>>
>>>>
>>>>
>>>> -> I would prefer the class PreMetaspaceValues to live inside an own
>>>> header in metaspace folder, and in the metaspace namespace like we did for
>>>> similar helpers.
>>>>
>>>>
>>>> I can definitely do that.
>>>>
>>>>
>>>>
>>>> -> I would take the "Pre" out of the name and the member names and just
>>>> name it "Snapshot" and the members "used" and "class used".
>>>>
>>>>
>>>> Again, I modeled it based on ParallelGC's PreGCValues class. But I can
>>>> rename it to Snapshot to generalize its use.
>>>>
>>>>
>>>>
>>>> -> I would probably have made PreMetaspaceValues a dumb structure and
>>>> added a function "MetaspaceAux::get_dimensions()" instead of adding the
>>>> implementation to the constructor and to the header file. At least I would
>>>> prefer the ctor implementation to the cpp file.
>>>>
>>>>
>>>> I can move it to a cpp file. This will also eliminate a cyclic
>>>> dependency I had to address by the class forward declaration.
>>>>
>>>>
>>>> Tony
>>>>
>>>>
>>>>
>>>>
>>>> Cheers, Thomas
>>>>
>>>> On Wed, May 8, 2019 at 4:20 PM Tony Printezis <tprintezis at twitter.com>
>>>> wrote:
>>>>
>>>>> Any chance of someone taking a look at this?
>>>>>
>>>>> http://cr.openjdk.java.net/~tonyp/8223575/webrev.0/
>>>>>
>>>>> As I said on the JIRA, users can be confused when they metaspace
>>>>> capacity shows as over 1G even though they asked for 128M. Breaking down
>>>>> the spaces, when coops are enabled, can address this confusion (and having
>>>>> the actual occupancy of each space separately is also a lot more
>>>>> informative and avoids guesswork). The output looks like this when coops
>>>>> are enabled:
>>>>>
>>>>> [10.090s][info][gc,metaspace     ] GC(8) Metaspace:
>>>>> 2130K->2130K(1056768K) ClassMetadata: 1906K->1906K(8192K) ClassSpace:
>>>>> 223K->223K(1048576K)
>>>>>
>>>>> and like this (i.e., what it was before the change) when coops are not
>>>>> enabled:
>>>>>
>>>>> [25.767s][info][gc,metaspace     ] GC(28) Metaspace:
>>>>> 8107K->8107K(10240K)
>>>>>
>>>>> A couple of notes on the changes:
>>>>>
>>>>> - I’m open to different suggestions for what to call ClassMetadata and
>>>>> ClassSpace. :-)
>>>>> - I didn’t know where to put the HEAP_CHANGE_FORMAT and
>>>>> HEAP_CHANGE_FORMAT_ARGS macros, so that they can be easily shared, and I
>>>>> ended up putting them in heap.hpp. Let me know if there’s a better place
>>>>> for them.
>>>>>
>>>>> Tony
>>>>>
>>>>>
>>>>> —————
>>>>> Tony Printezis | @TonyPrintezis | tprintezis at twitter.com
>>>>>
>>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>
>
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20190605/2bccfd48/attachment.htm>