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

Thu May 9 16:38:35 UTC 2019

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/20190509/26152ea4/attachment.htm>