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

Mon May 13 10:50:32 UTC 2019

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/20190513/d490f863/attachment.htm>