RFR: 8330198: Add some class loading related perf counters to measure VM startup [v3]

[Ioi Lam]

On Tue, 4 Jun 2024 05:13:58 GMT, David Holmes <dholmes at openjdk.org> wrote:

>>> The -Xlog:init (perhaps with a better name/tag!)
>> 
>> I'm all for a better naming scheme. Any suggestions?
>
>> -Xlog:init means "I want to see logs related to initialization", so it should enable all the counters for printing the related logs. 
> 
> I don't agree. Initialization logging could encompass many different things, some of which are individually controllable via different flags. Simply turning on init logging should not turn on all such flags. If you want that level of coupling then perhaps use init_counters (or something like that) to make it clear this is not a general log tag intended for any initialization code to use, but something you have chosen to tie to specific functionality.
> 
>> We may add several groups of counters in the future. We don't want to force the user to enumerate all these counters
> 
> It is not clear to me how you envisage that working. You want individual group switches plus a global one?

OK, I agree that not `-Xlog:init` logs are related to timing. 

We actually have an existing tag that's used for conditional logging. Perhaps we should use that instead?


./share/logging/logTag.hpp:  LOG_TAG(startuptime) \
./share/memory/universe.cpp:  TraceTime timer("Genesis", TRACETIME_LOG(Info, startuptime));
./share/prims/methodHandles.cpp:  TraceTime timer("MethodHandles adapters generation", TRACETIME_LOG(Info, startuptime));
./share/runtime/stubRoutines.cpp:  TraceTime timer(timer_msg, TRACETIME_LOG(Info, startuptime));
./share/runtime/threads.cpp:  TraceTime timer("Initialize module system", TRACETIME_LOG(Info, startuptime));
./share/runtime/threads.cpp:  TraceTime timer("Initialize java.lang classes", TRACETIME_LOG(Info, startuptime));
./share/runtime/threads.cpp:  TraceTime timer("Initialize java.lang.invoke classes", TRACETIME_LOG(Info, startuptime));
./share/runtime/threads.cpp:  TraceTime timer("Create VM", TRACETIME_LOG(Info, startuptime));
./share/runtime/threads.cpp:  { TraceTime timer("Start VMThread", TRACETIME_LOG(Info, startuptime));
./share/runtime/timerTrace.hpp://    TraceTime t("some timer", TIMERTRACE_LOG(Info, startuptime, tagX...));
./share/utilities/ostream.cpp:  // lazily create log file (at startup, LogVMOutput is false even

$ java -Xlog:startuptime --version
[0.010s][info][startuptime] StubRoutines generation initial stubs, 0.0006132 secs
[0.025s][info][startuptime] Genesis, 0.0145142 secs
[0.025s][info][startuptime] StubRoutines generation continuation stubs, 0.0000198 secs
[0.028s][info][startuptime] Interpreter generation, 0.0005919 secs
[0.028s][info][startuptime] StubRoutines generation final stubs, 0.0000717 secs
[0.028s][info][startuptime] MethodHandles adapters generation, 0.0000101 secs
[0.029s][info][startuptime] Start VMThread, 0.0000846 secs
[0.032s][info][startuptime] Initialize java.lang classes, 0.0036507 secs
[0.033s][info][startuptime] Initialize java.lang.invoke classes, 0.0002106 secs
[0.034s][info][startuptime] StubRoutines generation compiler stubs, 0.0015061 secs
[0.035s][info][startuptime] Initialize module system, 0.0017471 secs
[0.035s][info][startuptime] Create VM, 0.0305224 secs
java 23-internal 2024-09-17
Java(TM) SE Runtime Environment (build 23-internal-adhoc.iklam.zoo)
Java HotSpot(TM) 64-Bit Server VM (build 23-internal-adhoc.iklam.zoo, mixed mode, sharing)

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

PR Review Comment: https://git.openjdk.org/jdk/pull/18790#discussion_r1626256873