JDK-8227269 : Slow class loading when running with JDWP
  • Type: Bug
  • Component: core-svc
  • Sub-Component: debugger
  • Affected Version: 8,11,13,14,15
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2019-07-04
  • Updated: 2024-07-15
  • Resolved: 2020-03-27
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 13 JDK 14 JDK 15 Other
11.0.9-oracleFixed 13.0.4Fixed 14.0.2Fixed 15 b17Fixed openjdk8u262Fixed
Related Reports
Relates :  
JDK-8246223 - Windows build fails after JDK-8227269
Relates :  
JDK-8241750 - x86_32 build failure after JDK-8227269
Relates :  
JDK-8214892 - Delayed starting of debugging via jcmd
Relates :  
JDK-8336401 - Remove the option onjcmd from the jdwp agent
Relates :  
JDK-8214892 - Delayed starting of debugging via jcmd
Description
When debug mode is active (-agentlib:jdwp), an application spends a lot of time in JVM internals like Unsafe.defineAnonymousClass or Class.getDeclaredConstructors.Sometimes this happens on EDT and UI freezes occur.

If we look into the code, we'll see that whenever a new class is loaded and an event about it is delivered, when a garbage collection has occurred, classTrack_processUnloads iterates over all loaded classes to see if any of them have been unloaded. This leads to O(classCount * gcCount) performance, which in case of frequent GCs (and they are frequent, especially the minor ones) is close to O(classCount^2). In IDEA, we have quite a lot of classes, especially counting all lambdas, so this results in quite significant overhead.

Full analysis here: https://youtrack.jetbrains.com/issue/JBR-1611
Comments
Fix Request for 8u: Patch applies cleanly with automated path shuffling. It should be approved along with the companion bug JDK-8241750. This has soaked in 15u for about two months now and makes using JDWP to debug code which uses a lot of class loading feasible.
23-05-2020
Fix Request for 11u, 13u & 14u: Patch applies unchanged and should be approved along with the companion bug JDK-8241750 This has soaked in 15u for about two months now and makes using JDWP to debug code which uses a lot of class loading feasible.
23-05-2020
URL: https://hg.openjdk.java.net/jdk/jdk/rev/63a288f3f25a User: rkennke Date: 2020-03-27 10:26:03 +0000
27-03-2020
Updated O(1) implementation and review thread: https://mail.openjdk.java.net/pipermail/serviceability-dev/2019-December/030171.html
20-12-2019
A much simpler fix candidate than the Android one: http://cr.openjdk.java.net/~rkennke/JDK-8227269/webrev.00/ Currently testing.
22-11-2019
The discusson on https://bugzilla.redhat.com/show_bug.cgi?id=1751985 suggests there may be an Android fix that already addresses this issue.
19-09-2019
We regularly observe stacks like this in our freeze reports when debug agent is on: ... java.lang.invoke.MethodHandleNatives.linkCallSite 800ms java.lang.invoke.MethodHandleNatives.linkCallSiteImpl 800ms java.lang.invoke.CallSite.makeSite 800ms java.lang.invoke.BootstrapMethodInvoker.invoke 800ms java.lang.invoke.Invokers$Holder.invokeExact_MT 800ms java.lang.invoke.LambdaForm$DMH/0x000000080021ec40.invokeStatic 800ms java.lang.invoke.LambdaMetafactory.metafactory 800ms java.lang.invoke.InnerClassLambdaMetafactory.buildCallSite 800ms java.lang.invoke.InnerClassLambdaMetafactory.spinInnerClass 800ms jdk.internal.misc.Unsafe.defineAnonymousClass 800ms jdk.internal.misc.Unsafe.defineAnonymousClass0 800ms So this should affect lambdas creation, not only app warmup.
11-09-2019
The hook into JVMTI each time a class is loaded is only called once per class...ever. This is why I would not consider this a class loading performance issue. It's a book keeping performance issue since the cache of loaded classes is recreated every time there is a GC. Now it may very well be true that when a class is first loaded/prepared, the cost of notifying jvmti is high enough that this alone results in a performance issue during app warmup if there are a large number of classes loaded, but the real issue seems to be having to regenerated the cache every time there is a GC. This is where having a large number of classes plus a high frequency of GCs becomes an issue, even long after started, as noted in the original jetbrains bug.
05-08-2019
The issue is indeed in bookkeeping the loaded classes by debug agent, which seems to be done inside JVMTI event processing. From the code/snapshots, it seems to happen during class loading (or, more precisely, preparation) and not during GC, the GC rate seems to only affect the frequency of this inefficient bookkeeping.
05-08-2019
Is the synopsis for this CR accurate? Isn't the issue really just the debug agent's book keeping of the loaded classes? I don't think the debug agent is slowing down class loading in an significant way, but it is in affect slowing down GC because a GC will trigger a lot of book keeping work by the debug agent.
10-07-2019
JDK-8214892 might be something that can be used to work around this issue. Although pushed to 12, it's being reworked, so not sure what it will look like after that work is complete.
04-07-2019
Also see discussion on serviceabilty-dev: http://mail.openjdk.java.net/pipermail/serviceability-dev/2019-June/028435.html And more specifically, the following explanation which I provided: --------------------------------- With respect to the specific issue brought up in https://youtrack.jetbrains.com/issue/JBR-1611: "If we look into the code, we'll see that whenever a new class is loaded and an event about it is delivered, when a garbage collection has occurred, classTrack_processUnloads iterates over all loaded classes to see if any of them have been unloaded. This leads to O(classCount * gcCount) performance, which in case of frequent GCs (and they are frequent, especially the minor ones) is close to O(classCount^2). In IDEA, we have quite a lot of classes, especially counting all lambdas, so this results in quite significant overhead." The debug agent calls JVMTI GetLoadedClasses() during initialization to get a cache of all prepared classes. It keeps that cache up-to-date by getting JVMTI CLASS_PREPARE events. When there is a gc, the debug agent basically throws away the cache and creates a new one by calling GetLoadedClasses() again. It also compares the old and new caches to determine which classes where unloaded, and generates JDWP CLASS_UNLOAD events for them (if there is a debugger attached that wants them). It might be possible to defer initialization of the loaded classes cache (and any maintenance of it) until there is a debugger attached. I'm not sure if the only reason for the cache is for delivery of CLASS_UNLOAD events, but at first glance that appears to be the case. ---------------------------------
04-07-2019