Increased safepoint cleanup tasks in Java 11 (vs 8)

[Vitaly Davidovich]

On Wed, Jun 5, 2019 at 9:54 AM <coleen.phillimore at oracle.com> wrote:

>
>
> On 6/5/19 9:44 AM, Vitaly Davidovich wrote:
> > So after adding "cleanup" to ULF per Thomas' suggestion, I'm seeing the
> > following steps taking non-zero time:
> >
> >     - deflating idle monitors
> >     - updating inline caches
> >     - compilation policy safepoint handler
> >     - purging class loader data graph
> >     - resizing system dictionaries
> >
> > So I was wrong about this being string table rehashing.
>
> Hi, That's good because the string table rehashing should be very rare.
> >
> >
> https://github.com/openjdk/jdk11u/blob/737d8437886ad97c6ed21a25b9911c10b3886f61/src/hotspot/share/classfile/classLoaderData.hpp#L145
> > suggests
> > that CLDG purging is only done when using CMS.  This application isn't
> > using CMS (as mentioned, it's running ParallelGC).  It'd be nice if this
> > operation was entirely skipped and didn't show up in cleanup=info output.
> > I haven't (yet) checked if other cleanup ops (should?) have similar
> > "skipability".
>
> Yes, the purging class loader data graph and resizing system
> dictionaries doesn't actually happen at all (or often) but the cleanup
> tasks log when they test if they should happen.  I made a small patch to
> fix this recently. https://bugs.openjdk.java.net/browse/JDK-8224119

Oh, perfect - thanks Coleen!

>
>
> Coleen
>
> >
> > But as Aleksey mentioned, it sounds like safepoint cleanup itself is now
> > additionally predicated on monitor deflation, and not just IC buffer
> > cleanup.  I'll test out his suggested (experimental) VM option.
> >
> > On Wed, Jun 5, 2019 at 8:52 AM Vitaly Davidovich <vitalyd at gmail.com>
> wrote:
> >
> >>
> >> On Wed, Jun 5, 2019 at 8:47 AM Thomas Schatzl <
> thomas.schatzl at oracle.com>
> >> wrote:
> >>
> >>> Hi,
> >>>
> >>> On Wed, 2019-06-05 at 08:33 -0400, Vitaly Davidovich wrote:
> >>>> Hi all,
> >>>>
> >>> [...]
> >>>> My guess would be it's SAFEPOINT_CLEANUP_STRING_TABLE_REHASH because
> >>>> tiered compilation is disabled, ParallelGC is being used, and biased
> >>>> locking is disabled; all of this is the same as on Java 8.  Or might
> >>>> this be something else? Presumably it's something "new" in Java 11
> >>>> that triggers inside
> >>>>
> >>>
> https://github.com/openjdk/jdk11u/blob/737d8437886ad97c6ed21a25b9911c10b3886f61/src/hotspot/share/runtime/safepoint.cpp#L644
> >>>> Does anyone have ideas on pinpointing this further? How do I get the
> >>>> precise cleanup operation to show up in the log?
> >>> Given above link, considering the "TraceTime timer(name,
> >>> TRACETIME_LOG(Info, safepoint, cleanup))" lines, I would try adding
> >>> safepoint+cleanup=info to your log options.
> >>>
> >> Ah, thanks Thomas! I "saw" the "cleanup" in there too, but didn't
> connect
> >> the dots that I had to also include that as a ULF tag (since already had
> >> "safepoint").  Makes sense.  I will try.
> >>
> >>> Hth,
> >>>    Thomas
> >>>
> >>>
> >>>
>
>