JDK-8193513 : add support for printing a stack trace on class loading
  • Type: Enhancement
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 13
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2017-12-14
  • Updated: 2024-03-20
  • Resolved: 2023-07-08
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 22
22 b06Fixed
Related Reports
Relates :  
JDK-8311542 - Consolidate the native stack printing code
Relates :  
JDK-8311788 - ClassLoadUnloadTest fails on AIX after JDK-8193513
Relates :  
JDK-8328639 - Add support for including a native stack trace in -Xlog:exceptions
Description
Quite often it's useful to see why a given class is loaded (e.g., trying to reduce startup time for an app by avoiding unnecessary eager class loading). One way to do this is to see a stack trace when the VM loads a class. The only possibility currently is to add a static initializer to the class of interest. However, not only is this not always possible but it doesn't correlate with class loading but with class initialization.

In the graal-jvmci-8 fork, we added a -XX:+TraceClassLoadingStack option[1] to support this.

[~alanb] makes a good point that If something like this is added then it could be useful to specify a pattern or even a list of class names to avoid a stack trace for every class. That might help with interference too when there is a lot of class loading going on in different threads.

Update: See https://git.openjdk.org/jdk/pull/14553 for details on how this was implemented as an -Xlog option.

[1] https://github.com/graalvm/graal-jvmci-8/commit/25de3259d10b8606e318ceecbdf0195d3b1f196f
Comments
The test class is loaded by the launcher native code so an interesting example but not representative.
13-07-2023
An even better suggestion.
12-07-2023
I'd just use the name of the test class we start.
12-07-2023
Ok, StringConcatHelper sounds like a viable replacement.
11-07-2023
> I picked the StringCoding class as there are Java frames on the stack when it is loaded. Seems it is not loaded at all in some cases. on AIX we run into the (charset == ISO_8859_1.INSTANCE) case : https://github.com/openjdk/jdk/blob/master/src/java.base/share/classes/java/lang/String.java#L595 And this does not use StringCoding . In case COMPACT_STRINGS is off/disabled/not supported, we would probably face the same issue. Looking at the stack (example is from AIX) we could probably test for StringConcatHelper , what do you think ? It is present on Linux too. java -Xlog:class+load+cause -XX:LogClassLoadingCauseFor=java.lang.String Hello [0.037s][info][class,load,cause] Java stack when loading java.lang.String: [0.050s][info][class,load,cause] Java stack when loading java.lang.StringBuffer: [0.051s][info][class,load,cause] Java stack when loading java.lang.StringBuilder: [0.063s][info][class,load,cause] Java stack when loading java.lang.String$CaseInsensitiveComparator: [0.063s][info][class,load,cause] at java.lang.String.<clinit>(java.base/String.java:2065) [0.068s][info][class,load,cause] Java stack when loading java.lang.StringLatin1: [0.068s][info][class,load,cause] at java.lang.String.equals(java.base/String.java:1864) [0.068s][info][class,load,cause] at java.util.ImmutableCollections$Set12.<init>(java.base/ImmutableCollections.java:797) [0.068s][info][class,load,cause] at java.util.Set.of(java.base/Set.java:487) [0.068s][info][class,load,cause] at jdk.internal.reflect.Reflection.<clinit>(java.base/Reflection.java:58) [0.068s][info][class,load,cause] at java.security.AccessController.doPrivileged(java.base/AccessController.java:319) [0.068s][info][class,load,cause] at java.lang.reflect.AccessibleObject.<clinit>(java.base/AccessibleObject.java:529) [0.076s][info][class,load,cause] Java stack when loading java.lang.StringConcatHelper: [0.076s][info][class,load,cause] at java.lang.String.concat(java.base/String.java:2896) [0.076s][info][class,load,cause] at jdk.internal.util.SystemProps.fillI18nProps(java.base/SystemProps.java:195) [0.076s][info][class,load,cause] at jdk.internal.util.SystemProps.initProperties(java.base/SystemProps.java:133) [0.076s][info][class,load,cause] at java.lang.System.initPhase1(java.base/System.java:2158)
11-07-2023
I picked the StringCoding class as there are Java frames on the stack when it is loaded. That said, ClassLoadUnloadTest does not actually check for Java or native frames in the output of class+load+cause logging so any class guaranteed to be loaded during VM startup would suffice. How about java.lang.String?
10-07-2023
We see now failures on AIX in test 'runtime/logging/ClassLoadUnloadTest.java' . I created https://bugs.openjdk.org/browse/JDK-8311788 . Looks like the StringCoding class used as a command line parameter in ClassLoadUnloadTest.java is not used (load/init) on AIX in the example. But it is used on Linux. Should we replace it by another class e.g. StringConcatHelper ? This shows up early on both Linux and AIX .
10-07-2023
Changeset: 4a1fcb60 Author: Doug Simon <dnsimon@openjdk.org> Date: 2023-07-08 07:56:28 +0000 URL: https://git.openjdk.org/jdk/commit/4a1fcb6063fd5fad9ff9763359e7c79401e4fa92
08-07-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/14553 Date: 2023-06-20 09:19:42 +0000
20-06-2023
Unified Logging is simply based on tags, there is no support for any kind of filtering. You would need to add a diagnostic VM flag to perform the filtering.
20-06-2023
I'm printing the stack trace to an intermediate string and then appending that to the `LogStream` already being used for `-Xlog:class+load`. However, I've looked more into unified logging and don't see support for specifying an arbitrary "filter" argument for a log tag. Ideally, I'd want something like this: -Xlog:class+load+cause:filter=MyClass
19-06-2023
Can't answer the part about filtering but use LogStream for multi-line output.
18-06-2023
Prototype: https://github.com/dougxc/jdk/commit/c8b97b0539b4e01fa564298dce19e009bc2c5536 I'd like to implement this purely in terms of unified logging but still don't have answers to the above questions.
16-06-2023
Given that we need something that also works for boot classes, the JFR approach is incomplete. Is it possible to recast the JDK 8 implementation (https://github.com/graalvm/graal-jvmci-8/blob/master/src/share/vm/classfile/classFileParser.cpp#L4312) into something that use unified logging? I cannot work out: * how one would express the filtering * whether multi-line output is supported by unified logging
15-03-2022
I have port of these jvmci-8 changes.
09-04-2019
For reference, we've added support for this in jvmci-8 as it's just too useful when debugging unexpected loading of classes: https://github.com/graalvm/graal-jvmci-8/commit/2a5abbbc1d5d83b8d4cfa03bef137fde1eef3917 https://github.com/graalvm/graal-jvmci-8/commit/d6c6fc4eb05cf1566855444c7e55a1d41c1e3ab4
11-03-2019
Runtime Triage: This is not on our current list of priorities. We will consider this feature if we receive additional customer requirements.
22-01-2019
To view the class loading stack traces using JFR (JDK 9 or 10): [1] cp ${JAVA_HOME}/lib/jfr/default.jfc foo.jfc [2] Find the following block in foo.jfc, and change "enabled" from false to true: <event name="com.oracle.jdk.ClassLoad"> <setting name="enabled" control="class-loading-enabled">false</setting> <setting name="stackTrace">true</setting> <setting name="threshold">0 ms</setting> </event> [3] Run a command-like this: ${JAVA_HOME}/bin/java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=dumponexit=true,filename=foo.jfr,settings=foo.jfc -cp ~/tmp Foo [4] Start Java Mission Control from ${JAVA_HOME}/bin/jmc and open the foo.jfc [5] You can use the JMC UI to look at the call stack for how Foo is loaded. See attachment jmc_screenshot.png Notes: + boot classes that are loaded before JFR is initialized are not logged. + if you want to access foo.jfc programmatically, you'd need to use JFR APIs (which I don't know much about ....)
16-12-2017
The problem I see is that you have to be able to narrow it down else there is just far too much generally useless information - particularly if you want to see application class loading. And you also need to distinguish loading/resolution/initialization - depending on exactly what you are looking for.
14-12-2017
This new flag would be useful. FWIW. -Xlog:class+resolve=debug prints class resolution which could be used to trace when a class is loaded but it requires quite some work to find the first time it resolves C and then trace back the call stack (this can be quite burdensome in some case).
14-12-2017