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

[David Holmes]

On Tue, 20 Jun 2023 09:44:41 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 refreshed the contents of this pull request, and previous commits have been removed. The incremental views will show differences compared to the previous content of the PR. The pull request contains one new commit since the last revision:
> 
>   added TraceClassLoadingCause flag

Seems reasonable in principle, but I have a few suggested changes.

Thanks.

src/hotspot/share/oops/instanceKlass.cpp line 3743:

> 3741:                                              const ClassFileStream* cfs) const {
> 3742:   if (TraceClassLoadingCause != nullptr &&
> 3743:       (strcmp(TraceClassLoadingCause, "*") == 0 || strstr(external_name(), TraceClassLoadingCause) != nullptr))

Not sure if "contains" is the right way to match here ??

Also I don't see how this matches the example you gave for `Thread` because it only produced a few stacks. ??

src/hotspot/share/oops/instanceKlass.cpp line 3747:

> 3745:     stringStream st;
> 3746:     st.print_cr("Loading %s", external_name());
> 3747:     JavaThread::current()->print_stack_on(&st);

If this is called for a class loaded very early in VM initialization you may not yet have a current thread.

src/hotspot/share/oops/instanceKlass.cpp line 3748:

> 3746:     st.print_cr("Loading %s", external_name());
> 3747:     JavaThread::current()->print_stack_on(&st);
> 3748:     tty->print_raw(st.as_string());

This should be integrated with the UL below. When logging is enabled dump the stacktrace from the stringStream to the UL stream - probably at debug, or even trace, level. You need the diagnostic flag to set the filter, but it should still be controlled by the UL settings IMO.

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

Changes requested by dholmes (Reviewer).

PR Review: https://git.openjdk.org/jdk/pull/14553#pullrequestreview-1489795735
PR Review Comment: https://git.openjdk.org/jdk/pull/14553#discussion_r1236418878
PR Review Comment: https://git.openjdk.org/jdk/pull/14553#discussion_r1236419495
PR Review Comment: https://git.openjdk.org/jdk/pull/14553#discussion_r1236406192