RFR(S) 8189688: NMT: Report per-class load metadata information
Thomas Stüfe
thomas.stuefe at gmail.com
Thu Oct 26 12:53:05 UTC 2017
Hi Zhengyu,
one more thing, your output does not seem to be included in the final NMT
report when the VM shuts down, could this be added too?
Thanks! Thomas
On Wed, Oct 25, 2017 at 7:00 AM, Thomas Stüfe <thomas.stuefe at gmail.com>
wrote:
> Hi Zhengyu,
>
> On Tue, Oct 24, 2017 at 8:04 PM, Zhengyu Gu <zgu at redhat.com> wrote:
>
>> Hi Thomas,
>>
>> On 10/24/2017 12:08 PM, Thomas Stüfe wrote:
>>
>>> Hi Zhengyu,
>>>
>>> - VM_PrintMetadata still has the _unit member, but I see it nowhere used.
>>>
>>> - I would have split the summary between class and non-class area, that
>>> may have been more useful. But this is a matter of taste, I leave it up to
>>> you.
>>>
>>> Agree, should go little further.
>>
>> Summary:
>> Total class loaders= 754 capacity= 67528.00KB used= 61216.88KB
>> free= 9453.11KB waste= 38.73KB
>> Metadata capacity= 58780.00KB used= 54053.45KB
>> free= 4726.55KB waste= 36.38KB
>> Class data capacity= 8748.00KB used= 7163.43KB
>> free= 1584.57KB waste= 2.35KB
>>
>> For anonymous classes= 580 capacity= 2732.00KB used= 1065.06KB
>> free= 1666.94KB waste= 16.27KB
>> Metadata capacity= 2152.00KB used= 738.46KB
>> free= 1413.54KB waste= 16.27KB
>> Class data capacity= 580.00KB used= 326.60KB
>> free= 253.40KB waste= 0.00KB
>>
>>
>>
> Nice, thanks :)
>
>
>> Updated webrev: http://cr.openjdk.java.net/~zgu/8189688/webrev.03/
>>
>>
> All is well. Note that you could reduce the footprint of your change
> somewhat by defining a structure like this:
>
> struct numbers_t { size_t cap; size_t used; size_t free; size_t waste; }
>
> and replacing the many members in PrintCLDMetaspaceInfoClosure with
> instances of this structure:
>
> numbers_t total;
> numbers_t total_class;
> numbers_t total_anon;
> numbers_t total_anon_class;
>
> Depending on how far you go, your code could deflate quite a bit. Give the
> structure a default ctor and your large initializer list goes away; give it
> a printing function and you reduce print-summary() to four function calls;
> with something like an numbers_t::add(size_t cap, size_t used, size_t free,
> size_t waste) you can reduce the additions in PrintCLDMetaspaceInfoClosure::print_metaspace()
> to four lines.
>
> Just a suggestion, I leave it up to you if you do this.
>
> Lines 3108 and 3129 miss each a space before BytesPerWord. Change looks
> fine otherwise.
>
> Thanks, Thomas
>
>
> Thanks,
>>
>> -Zhengyu
>>
>>
>> All else looks fine to me now. I do not need another review.
>>>
>>> Thanks for your work, this will come in handy!
>>>
>>> ..Thomas
>>>
>>> On Tue, Oct 24, 2017 at 5:08 PM, Zhengyu Gu <zgu at redhat.com <mailto:
>>> zgu at redhat.com>> wrote:
>>>
>>> Hi Thomas,
>>>
>>>
>>> Not sure whether we misunderstood each other. I was thinking of
>>> something in the line of:
>>>
>>> <<<<
>>> ....
>>> ClassLoader: jdk/internal/reflect/DelegatingClassLoader
>>> Metadata:
>>> capacity: 5.00KB used: 3.32KB free: 1.68KB
>>> waste: 0.00KB
>>> Class data:
>>> capacity: 1.00KB used: 0.54KB free: 0.46KB
>>> waste: 0.00KB
>>>
>>> ClassLoader: for anonymous class
>>> Metadata:
>>> capacity: 1.00KB used: 1.00KB free: 0.00KB
>>> waste: 0.00KB
>>> Class data:
>>> capacity: 1.00KB used: 0.64KB free: 0.36KB
>>> waste: 0.00KB
>>> ....
>>>
>>> Summary:
>>> XX class loaders encountered, total capacity: xx, total waste:
>>> xx.
>>>
>>> Peak usage by class loader: xxxx
>>> >>>>
>>>
>>> Added summary lines:
>>>
>>> Total class loaders= 56 capacity= 6378.00KB used=
>>> 6205.08KB free= 172.92KB waste= 1.44KB
>>> For anonymous classes= 54 capacity= 212.00KB used= 96.95KB
>>> free= 115.05KB waste= 0.94KB
>>>
>>>
>>>
>>>
>>> These numbers would not be interpretation, just a convenience to
>>> the reader to get a clear picture.
>>>
>>> It even may be useful to separate the output between basic and
>>> detailed mode, and in basic mode omit all the single class
>>> loaders and just print the summary line.
>>>
>>> Updated webrev:
>>> http://cr.openjdk.java.net/~zgu/8189688/webrev.01/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.01/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.01/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.01/index.html>>
>>>
>>>
>>>
>>> metaspace.hpp:
>>>
>>> I would have preferred to keep scale_unit file local static
>>> instead of exposing it via MetaspaceAux, because it does not
>>> really have anything to do with metaspace.
>>>
>>> Fixed
>>>
>>>
>>> Otherwise ok.
>>>
>>> ---
>>>
>>> metaspace.cpp
>>>
>>> - ChunkManager::print_statistics(): thanks for reusing this
>>> function!
>>> -> Scale can only be ever 1, K, M, G, yes? So, could you
>>> add an assert at the start of the function, and a comment at the
>>> prototype or function head?
>>> -> Also, now that ChunkManager::print_statistics() takes a
>>> scale, could you please change the printout to use floats like
>>> you did in PrintCLDMetaspaceInfoClosure::print_metaspace()?
>>>
>>> Done.
>>>
>>>
>>> Chunkmanager (non-class):
>>> 0 specialized (128 bytes) chunks, total 0.00KB
>>> 0 small (512 bytes) chunks, total 0.00KB
>>> 0 medium (8192 bytes) chunks, total 0.00KB
>>> 0 humongous chunks, total 0.00KB
>>> total size: 0.00KB.
>>> Chunkmanager (class):
>>> 0 specialized (128 bytes) chunks, total 0.00KB
>>> 0 small (256 bytes) chunks, total 0.00KB
>>> 0 medium (4096 bytes) chunks, total 0.00KB
>>> 0 humongous chunks, total 0.00KB
>>> total size: 0.00KB.
>>>
>>>
>>> - I am concerned about races in
>>> PrintCLDMetaspaceInfoClosure::do_cld(ClassLoaderData* cld).
>>> Maybe my understanding is limited. We bail if cld->is_unloading.
>>> But nothing prevents a ClassLoaderDataGraph from starting to
>>> unload a ClassLoaderData and tearing down the Metaspace after we
>>> started printing it in another thread, right? Also, I do not see
>>> any fences.
>>>
>>> So, I wonder whether PrintCLDMetaspaceInfoClosure should run in
>>> lock protection. And then, I wonder if it would be good to
>>> separate data gathering and printing. We print to a (at least in
>>> principle) unknown output stream, which may be doing slow File
>>> IO or even Network IO. Doing this under lock protection seems
>>> not a good idea (but I see other places where this happens too).
>>>
>>> For an example, see ChunkManager::get_statistic() vs
>>> ChunkManager::print_statistic(). Could you do the same, have a
>>> data gathering step where you collect your
>>> <capacity/used/free/waste> quadrupel in a variable sized list of
>>> structures in memory, and print it out in a separate step? I
>>> realize though that the effort would be larger than for what we
>>> did in ChunkManager::get_statistic(), where we only fill a
>>> structure.
>>>
>>>
>>> Unlike other NMT queries, this query is executed at a safepoint by
>>> VMThread, so it should be okay.
>>>
>>> Updated webrev: http://cr.openjdk.java.net/~zgu/8189688/webrev.02/
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.02/>
>>>
>>> Thanks,
>>>
>>> -Zhengyu
>>>
>>>
>>> ------
>>>
>>> vm_operations.hpp
>>>
>>> - VM_PrintMetadata : do we still need _unit?
>>>
>>>
>>> Thanks,
>>>
>>> -Zhengyu
>>>
>>>
>>>
>>> Thanks!
>>>
>>> Thomas
>>>
>>>
>>>
>>> On 10/23/2017 11:08 AM, Thomas Stüfe wrote:
>>>
>>>
>>>
>>> On Mon, Oct 23, 2017 at 5:03 PM, Zhengyu Gu
>>> <zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>>>
>>> wrote:
>>>
>>>
>>>
>>> Okay. So this is important for understanding
>>> cases
>>> where we have
>>> a large number of miniscule class loaders,
>>> each one
>>> only having
>>> a few numbers of chunks. In this case, would
>>> it be
>>> useful to
>>> have a running total of "free" and "waste",
>>> too? Or
>>> even better,
>>> also average and peak values of "free" and
>>> "waste" (to tell
>>> apart cases where you have one outlier vs
>>> cases where
>>> just all
>>> metaspaces waste a lot of memory).
>>> Just out of curiosity, I looked at
>>> http://cr.openjdk.java.net/~zgu/cld_metaspace/wildfly.txt
>>> <http://cr.openjdk.java.net/~zgu/cld_metaspace/wildfly.txt>
>>> <http://cr.openjdk.java.net/~z
>>> gu/cld_metaspace/wildfly.txt
>>> <http://cr.openjdk.java.net/~zgu/cld_metaspace/wildfly.txt>>
>>> <http://cr.openjdk.java.net/~z
>>> gu/cld_metaspace/wildfly.txt
>>> <http://cr.openjdk.java.net/~zgu/cld_metaspace/wildfly.txt>
>>> <http://cr.openjdk.java.net/~z
>>> gu/cld_metaspace/wildfly.txt
>>> <http://cr.openjdk.java.net/~zgu/cld_metaspace/wildfly.txt>>>
>>> and
>>> it seems that "free" is the problem, not
>>> "waste"? So I
>>> guess
>>> what happens is that all the little
>>> classloaders
>>> allocate just
>>> enough memory to push them over
>>> "_small_chunk_limit=4",
>>> so they
>>> allocate the first medium chunk, from which
>>> then they
>>> take a
>>> small bite and leave the rest laying around?
>>>
>>> Yes. The free space of anonymous classes should be
>>> counted
>>> as waste,
>>> in my opinion. I am not sure if everyone agrees,
>>> so I took the
>>> summary line out of this patch.
>>>
>>> I would be more than happy to restore the summary
>>> line, if
>>> you find
>>> it is useful :-)
>>>
>>>
>>> I agree with you. Typically class loaders stop loading
>>> at some
>>> point, especially these tine ones, and often will not
>>> resume
>>> loading. So, effectivly, the space is wasted. It still
>>> helps to
>>> distinguish "free" in the current chunks from "free" in
>>> the
>>> other chunks to tell this situation apart from a
>>> situation where
>>> we have just a bug in metaspace chunk handling
>>> preventing us to
>>> use up our chunks.
>>>
>>>
>>> The latter would be an important
>>> addition,
>>> regardless
>>> if this is
>>> for customers or for us. Chunks
>>> idling in
>>> freelists can
>>> make a
>>> huge impact, and unfortunately this
>>> may happen
>>> in perfectly
>>> valid cases. See e.g. our JEP
>>> "
>>> https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>>>
>>> <
>>> https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690
>>> <https://bugs.openjdk.java.net/browse/JDK-8166690>>>>". We have
>>> already a printing routine for free
>>> chunks, in
>>> ChunkManager::print_all_chunkmanagers().
>>> Could
>>> you add
>>> this to
>>> your output?
>>>
>>>
>>> Make sense! Could you recommend what data
>>> and
>>> format you
>>> would like
>>> to see?
>>>
>>>
>>>
>>> Would not
>>> ChunkManager::print_all_chunkmanagers() be
>>> sufficient?
>>>
>>> Okay, I might need to tweak output format.
>>>
>>>
>>> Fine by me. Nothing depends on it yet.
>>>
>>> Thanks, Thomas
>>>
>>> Thanks,
>>>
>>> -Zhengyu
>>>
>>>
>>>
>>> -------------
>>>
>>> Other than above notes, the changes
>>> seem
>>> straighforward, I did
>>> not see anything wrong. Minor nits:
>>>
>>> - PrintCLDMetaspaceInfoClosure::_out,
>>> _scale
>>> and _unit
>>> could all
>>> be constant (with _out being a
>>> outputStream*
>>> const).
>>> - We also do not need to provide
>>> scale *and*
>>> unit as
>>> argument,
>>> one can be deduced from the other.
>>> This would
>>> also prevent
>>> mismatches.We do need scale here,
>>> since nmt
>>> command
>>> line can set
>>> scale and we do
>>>
>>> have to honor that.
>>>
>>> However, passing unit is ugly! I don't
>>> want to
>>> introduce
>>> inverse
>>> dependence (metaspace -> nmt), which is
>>> also ugly.
>>>
>>>
>>> Yes, that would be regrettable.
>>>
>>> Probably should move scale mapping code
>>> from
>>> NMTUtil to a
>>> common util?
>>>
>>>
>>>
>>> That would be possible, these functions
>>> (scale_from_name etc)
>>> are simple enough to be moved to a generic
>>> file.
>>> However, if you
>>> pass scale, deducing the string that goes with
>>> it is
>>> trivial and
>>> I would have no qualms doing this by hand in
>>> metaspace.cpp. But
>>> it is a matter of taste.
>>>
>>>
>>> I did not look closely at locking
>>> issues, I assume
>>> MetaspaceAux::print_metadata() is
>>> supposed to
>>> run only in
>>> Safepoints?
>>>
>>>
>>> No. sum_xxx_xxx_in_use queries are
>>> guarded by locks.
>>>
>>> Thanks,
>>>
>>> -Zhengyu
>>>
>>>
>>> Thanks, Thomas
>>>
>>>
>>>
>>> Thanks & Kind Regards, Thomas
>>>
>>>
>>>
>>>
>>>
>>>
>>> On Fri, Oct 20, 2017 at 4:00 PM,
>>> Zhengyu Gu
>>> <zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>>
>>> <mailto:zgu at redhat.com
>>> <mailto:zgu at redhat.com> <mailto:zgu at redhat.com
>>> <mailto:zgu at redhat.com>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>>
>>>
>>> <mailto:zgu at redhat.com
>>> <mailto:zgu at redhat.com> <mailto:zgu at redhat.com
>>> <mailto:zgu at redhat.com>>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>
>>> <mailto:zgu at redhat.com <mailto:zgu at redhat.com>>>>>> wrote:
>>>
>>> Up to now, there is little
>>> visibility
>>> into how
>>> metaspaces
>>> are used,
>>> and by whom.
>>>
>>> This proposed enhancement gives
>>> NMT the
>>> ability to
>>> report
>>> metaspace
>>> usages on per-classloader level,
>>> via a
>>> new NMT command
>>> "metadata"
>>>
>>>
>>> For example:
>>>
>>> 2496:
>>> Metaspaces:
>>> Metadata space: reserved=
>>> 8192KB
>>> committed= 5888KB
>>> Class space: reserved=
>>> 1048576KB
>>> committed= 640KB
>>>
>>> Per-classloader metadata:
>>>
>>> ClassLoader: for anonymous class
>>> Metadata capacity=
>>> 5.00KB
>>> used= 1.16KB
>>> free= 3.84KB waste=
>>> 0.05KB
>>> Class data capacity=
>>> 1.00KB
>>> used= 0.59KB
>>> free= 0.41KB waste=
>>> 0.00KB
>>>
>>> ....
>>>
>>> ClassLoader: <bootloader>
>>> Metadata capacity=
>>> 5640.00KB
>>> used= 5607.42KB
>>> free= 32.58KB waste=
>>> 0.46KB
>>> Class data capacity=
>>> 520.00KB
>>> used= 500.94KB
>>> free= 19.06KB waste=
>>> 0.02KB
>>>
>>>
>>> Bug:
>>> https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>>
>>> <
>>> https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>>>
>>> <
>>> https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>>
>>> <
>>> https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>
>>> <https://bugs.openjdk.java.net
>>> /browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688
>>> <https://bugs.openjdk.java.net/browse/JDK-8189688>>>>>
>>> Webrev:
>>> http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>>
>>> <
>>> http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> >>>>
>>> <
>>> http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>>
>>> <
>>> http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html>
>>> <http://cr.openjdk.java.net/~z
>>> gu/8189688/webrev.00/index.html
>>> <http://cr.openjdk.java.net/~zgu/8189688/webrev.00/index.html
>>> >>>>>
>>>
>>> Test:
>>>
>>> hotspot_tier1_runtime,
>>> fastdebug and
>>> release on
>>> x64 Linux.
>>>
>>> Thanks,
>>>
>>> -Zhengyu
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>
More information about the hotspot-runtime-dev
mailing list