A little more advice on the metaspace gc log

Kirk Pepperdine kirk.pepperdine at gmail.com
Fri Sep 28 06:37:10 UTC 2018

> On Sep 27, 2018, at 11:24 PM, nijiaben <nijiaben at perfma.com> wrote:
> hi all,
> Thank you so much for the follow-up about the patch that I mentioned about the metaspace last week(A Bug Of Metaspace After Full GC <http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2018-September/023329.html>).However,I still have the other suggestion about the metaspace. Please allow me to describe it briefly.
> Still in the Full GC scenario, we will print the size of the metaspace in the GC log. Suppose we set -XX:MetaspaceSize=100M -XX:MaxMetaspaceSize=100M, which means a metaspace full GC should be triggered once the metaspace usage reaches to 100M, but actually we find the problem from the gc log and only 70899KB is used in the metaspace. 
> [Full GC (Metadata GC Threshold) [PSYoungGen: 5092K->0K(132096K)] [ParOldGen: 85822K->60451K(181760K)] 90914K->60451K(313856K), [Metaspace: 70899K->70899K(1136640K)], 0.1482072 secs] [Times: user=0.52 sys=0.00, real=0.15 secs]
> First let’s take a look at the code that prints this line of gc log which really depends on the size used by metaspace.
> void MetaspaceAux::print_metaspace_change(size_t prev_metadata_used) {
>   gclog_or_tty->print(", [Metaspace:");
>   if (PrintGCDetails && Verbose) {
>     gclog_or_tty->print(" "  SIZE_FORMAT
>                         "->" SIZE_FORMAT
>                         "("  SIZE_FORMAT ")",
>                         prev_metadata_used,
>                         used_bytes(),
>                         reserved_bytes());
>   } else {
>     gclog_or_tty->print(" "  SIZE_FORMAT "K"
>                         "->" SIZE_FORMAT "K"
>                         "("  SIZE_FORMAT "K)",
>                         prev_metadata_used/K,
>                         used_bytes()/K,
>                         reserved_bytes()/K);
>   }
>   gclog_or_tty->print("]");
> }
> However, the basis for triggering metaspace Full GC is not based on the real usage of metaspace, but the memory size of metaspace committed.
> size_t MetaspaceGC::allowed_expansion() {
>   size_t committed_bytes = MetaspaceAux::committed_bytes();
>   size_t capacity_until_gc = capacity_until_GC();
>   assert(capacity_until_gc >= committed_bytes,
>         err_msg("capacity_until_gc: " SIZE_FORMAT " < committed_bytes: " SIZE_FORMAT,
>                 capacity_until_gc, committed_bytes));
>   size_t left_until_max  = MaxMetaspaceSize - committed_bytes;
>   size_t left_until_GC = capacity_until_gc - committed_bytes;
>   size_t left_to_commit = MIN2(left_until_GC, left_until_max);
>   return left_to_commit / BytesPerWord;
> }
> Obviously, if we create a lot of classloaders, each of them will correspond to a metaspace data structure. The usage of our metaspace refers to the real in Metanchunk. The size of the memory is allocated, but Metanchunk is not all used up. This problem is simplified. Just like the fragmentation of the CMS GC, we have a certain gap between the memory committed and the memory used, and trigger the metaspace Full GC is based on the size of the committed, so the user feels like the metaspace doesn’t reach our threshold triggers the Full GC, which seems doubtful.
> Therefore, I would like to make a small suggestion that for the scenario of Full GC, the committed memory size instead of the used memory size will be printed more directly when we print the GC log of metaspace, which will make the user to see it more clearly and turn out that the threshold of metaspace has already reached the trigger of Full GC.
> The modified log is more conspicuous and indeed triggered when reaching 100M, but it will bring another drawback that we don‘t know how much metaspace really have been used.
> [Full GC (Metadata GC Threshold) [PSYoungGen: 5092K->0K(132096K)] [ParOldGen: 81395K->60429K(181248K)] 86488K->60429K(313344K), [Metaspace: 102400K->70599K(1136640K)], 0.1330421 secs] [Times: user=0.46 sys=0.00, real=0.13 secs]
> This issue will have some impact on various GC strategies.
> What do you think about this? I am looking forward to your reply.

Great detective work..

Adding committed to the log seems like a reasonable thing to do. That said there is a lot of tooling that is used to used before->used after(size of pool). Changing the def is a compilation for tools that work across many JVM versions. If you are to add new information in the log could I kindly suggest that you add it in a new column so that it’s distinctly committed or distinctly acclimated.

Kind regards,

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20180927/d6678cec/attachment-0001.html>

More information about the hotspot-gc-dev mailing list