RFR: 8193513: add support for printing a stack trace on class loading [v4]

Doug Simon dnsimon at openjdk.org
Mon Jul 3 21:31:56 UTC 2023


On Sun, 2 Jul 2023 21:51:59 GMT, Doug Simon <dnsimon at openjdk.org> wrote:

>> In the development of libgraal, it has been very useful to see why a given class is loaded (e.g., trying to reduce startup time by avoiding unnecessary eager class loading). One way to do this is to see the 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.
>> 
>> This PR proposes a `TraceClassLoadingCause` VM flag:
>> 
>> 
>>   product(ccstr, TraceClassLoadingCause, nullptr, DIAGNOSTIC,               \
>>           "Print a stack trace when loading a class whose fully"            \
>>           "qualified name contains this string ("*" matches "             \
>>           "any class).")                                                    \
>> 
>> 
>> I would have liked to implement this using Unified Logging but UL has no support for filtering on the class names.
>> 
>> Example usage:
>> 
>> java -XX:+UnlockDiagnosticVMOptions -XX:TraceClassLoadingCause=Thread --version
>> Loading java.lang.Thread
>> Loading java.lang.Thread$FieldHolder
>> Loading java.lang.Thread$Constants
>> Loading java.lang.Thread$UncaughtExceptionHandler
>> Loading java.lang.ThreadGroup
>> Loading java.lang.BaseVirtualThread
>> Loading java.lang.VirtualThread
>> Loading java.lang.ThreadBuilders$BoundVirtualThread
>> Loading java.lang.Thread$State
>> 	at jdk.internal.misc.VM.toThreadState(java.base/VM.java:336)
>> 	at java.lang.Thread.threadState(java.base/Thread.java:2731)
>> 	at java.lang.Thread.isTerminated(java.base/Thread.java:2738)
>> 	at java.lang.Thread.getThreadGroup(java.base/Thread.java:1957)
>> 	at java.lang.ref.Reference$1.startThreads(java.base/Reference.java:314)
>> 	at java.lang.System.initPhase1(java.base/System.java:2206)
>> Loading java.lang.Thread$ThreadIdentifiers
>> 	at java.lang.Thread.<init>(java.base/Thread.java:734)
>> 	at java.lang.Thread.<init>(java.base/Thread.java:1477)
>> 	at java.lang.ref.Reference$ReferenceHandler.<init>(java.base/Reference.java:198)
>> 	at java.lang.ref.Reference.startReferenceHandlerThread(java.base/Reference.java:300)
>> 	at java.lang.ref.Reference$1.startThreads(java.base/Reference.java:318)
>> 	at java.lang.System.initPhase1(java.base/System.java:2206)
>> Loading java.lang.ref.Finalizer$FinalizerThread
>> 	at java.lang.ref.Finalizer.startFinalizerThread(java.base/Finalizer.java:187)
>> 	at java.lang.ref.Reference$1.startThreads(java.base/Reference.java:319)
>> 	at java.lang.Sy...
>
> Doug Simon has updated the pull request incrementally with one additional commit since the last revision:
> 
>   add class+load+cause and make its output independent of class+load

The `runtime/logging/RedefineClasses.java` test fails as a result of these changes. This seems to happen for either of the following reasons:
1. The test times out due to native stack logging being so slow. The test uses `-Xlog:all=trace:file=all.log` so will indiscriminately log `class+load+cause+native` for every class loaded and the test seems to load a lot of classes.
2. The test crashes the VM as `VMError::print_native_stack` is apparently not safe to call in all class loading contexts. The attached 
[hs_err_pid46945.log](https://github.com/openjdk/jdk/files/11941187/hs_err_pid46945.log) shows one such example.

Unless someone can suggest a reliable way to workaround both these issues, I propose to drop `class+load+cause+native` logging.

-------------

PR Comment: https://git.openjdk.org/jdk/pull/14553#issuecomment-1619169099


More information about the hotspot-dev mailing list