ClassLoaderStats VM operation can be quadratic in some cases

[Thomas Stüfe]

Hi Jean Philippe,

These lookups are needed since we accumulate the cost for anonymous/hidden
classes as well as official classes to the loader, and the latter are
loaded under a separate CLD.

Capping the hashtable content? How would this work. You would get
incomplete results.

One could make the hashtable somewhat broader, however the hashtable size
is a compile time argument, and which size is the right size? With a loader
count of 40K, even 1000 or 2000 buckets would be overbooked by factor 20 or
so.

Looking more closely at the code, I see at least one optimization
possibility in ResourceHashMap: the typical "if (table.get(k)==NULL)
table.put(k,v);" pattern calls lookup twice. This could be done with one
lookup. I opened a follow up issue:
https://bugs.openjdk.java.net/browse/JDK-8244733 .

Also, it is even worse than o(n^2) since we also
call ClassLoaderStatsClosure::addEmptyParents() to collect stats for empty
parent class loaders for every loader, which for every loader crawls up the
loader chain and looks up the loader. However, I am not sure at all why we
do this. I am not a JFR developer, maybe someone from the Oracle JFR team
can answer that? The resulting numbers for these empty loaders would be of
course zero, since they have not loaded anything. Is it just to make them
show up in the class loader list?

Note I am not a JFR developer. I'll wait for the JFR devs to chime in.

Cheers, Thomas


On Thu, May 7, 2020 at 12:03 PM Jean-Philippe BEMPEL <
jean-philippe.bempel at datadoghq.com> wrote:

> Hello all,
>
> We have a customer complaining about long VM operations especially
> ClassLoaderStats using JFR. This operation can last several seconds!
>
> Looking into the recording of this application, we realize that there is
> 40K+ ClassLoaders, which is unusual, maybe a classloader leak, but this is
> not the point, as without JFR the application is running fine.
>
> I can reproduce the issue with this simple class:
>
> package com.bempel.sandbox;
>
> import java.net.URL;
> import java.net.URLClassLoader;
> import java.util.ArrayList;
> import java.util.List;
>
> public class JFRClassLoaderStatsIssue {
>
>     private static List<ClassLoader> classLoaderList = new ArrayList<>();
>
>     public static void main(String[] args) throws Exception {
>         URL location =
>
> JFRClassLoaderStatsIssue.class.getProtectionDomain().getCodeSource().getLocation();
>         for (int i = 0; i < 40_000; i++) {
>             URLClassLoader classLoader = new URLClassLoader(new
> URL[]{location});
>
> Class.forName(JFRClassLoaderStatsIssue.class.getCanonicalName(),
> true, classLoader);
>             classLoaderList.add(classLoader);
>         }
>     }
> }
>
> Running with on JDK11 with the following command line:
>
> java -Xlog:safepoint
> -XX:StartFlightRecording=dumponexit=true,filename=issue.jfr
> -XX:-UseBiasedLocking -cp build/classes/java/main
> com.bempel.sandbox.JFRClassLoaderStatsIssue
>
> output:
> [...]
> [0.861s][info][safepoint] Entering safepoint region:
> ClassLoaderStatsOperation
> [6.593s][info][safepoint] Leaving safepoint region
> [6.593s][info][safepoint] Total time for which application threads were
> stopped: 5.7324145 seconds, Stopping threads took: 0.0000127 seconds
> [...]
>
> Looking into ClassLoaderStatsClosure::do_cld method [1] we can see that
> each classloader is inserted into a hashtable for the duration of the VM
> operation.
> but this hashtable is fixed in size to 256 buckets. At some point, lookups
> and insertions become linear (too many collisions). Those lookups and
> insertions are done for each Classloader => O(n^2)
>
> With a small number of classloaders it's fine, but with 40K it's not ok :)
> My thought about this issue would be to cap the number of classloaders
> inserted into the hashmap based on _total_loaders field counter (which BTW
> seems not used at all).
>
> Thanks for looking into it.
>
> Kind Regards,
> Jean-Philippe Bempel
> [1]
>
> https://github.com/openjdk/jdk/blob/master/src/hotspot/share/classfile/classLoaderStats.cpp#L48
>