RFR: 8148630: Convert TraceStartupTime to Unified Logging

Rachel Protacio rachel.protacio at oracle.com
Wed Feb 10 21:46:19 UTC 2016


Please review this fix for 
https://bugs.openjdk.java.net/browse/JDK-8148630, converting 
-XX:+TraceStartupTime to -Xlog:startuptime, with the old option aliased 
to the new logging one since it is product-level.

Open webrev: http://cr.openjdk.java.net/~rprotacio/8148630/

Contains new jtreg test, and tested using JPRT. Currently running RBT 
quick and non-colo tests to verify embedded/ARM (testing delayed because 
of RBT's being down); I'll reply with an update if they don't pass.

Note that in memory/metaspaceShared.cpp, I've added curly brackets 
around the MetaspaceShared::preload_and_dump(TRAPS) code before exit(0) 
is called because Dmitry noticed that without it, the timer's destructor 
was not in fact being called, so it wouldn't print out the info.

Also, note that I have altered the printing scheme for the TraceTime 
objects, so that they print the title and time all at once. In the 
original code, there was often interleaving and therefore potentially 
misleading output because the title was printed at initialization, and 
the time printed at destruction. There was no guarantee of order or 
correlation in the printed output.

Original output:

    $ java -XX:+TraceStartupTime -version
    [Create VM[StubRoutines generation 1, 0.0020992 secs]
    [Genesis, 0.0707006 secs]
    [TemplateTable initialization, 0.0000252 secs]
    [Interpreter generation, 0.0078040 secs]
    [StubRoutines generation 2, 0.0016265 secs]
    [Start VMThread, 0.0003409 secs]
    [Initialize java.lang classes, 0.1160241 secs]
    [MethodHandles adapters generation, 0.0003382 secs]
    , 0.3457703 secs]
    java version "9-internal"
    Java(TM) SE Runtime Environment (fastdebug build
    Java HotSpot(TM) 64-Bit Server VM (fastdebug build
    9-internal+0-2016-02-03-174035.rprotaci.clean, mixed mode)

New output:

    $ java -Xlog:startuptime -version
    [0.017s][info][startuptime] StubRoutines generation 1, 0.0008210 secs
    [0.078s][info][startuptime] Genesis, 0.0614780 secs
    [0.078s][info][startuptime] TemplateTable initialization, 0.0000223 secs
    [0.084s][info][startuptime] Interpreter generation, 0.0054339 secs
    [0.131s][info][startuptime] StubRoutines generation 2, 0.0015735 secs
    [0.132s][info][startuptime] Start VMThread, 0.0003322 secs
    [0.189s][info][startuptime] Initialize java.lang classes, 0.0568726 secs
    [0.217s][info][startuptime] MethodHandles adapters generation,
    0.0002843 secs
    [0.218s][info][startuptime] Create VM, 0.2115240 secs
    java version "9-internal"
    Java(TM) SE Runtime Environment (fastdebug build
    Java HotSpot(TM) 64-Bit Server VM (fastdebug build
    9-internal+0-2016-02-01-141226.rprotaci.8148630, mixed mode)

So the new output for non-TraceStartupTime options looks the same as 
before, but all the printing is done during destruction.

Thank you,

More information about the hotspot-runtime-dev mailing list