Hi David,
On 2/11/2016 1:30 AM, David Holmes wrote:
> Hi Rachel,
>
> Can we internalize more of this into the TraceTime class - eg instead of:
>
> TraceTime timer("Interpreter generation",
> log_is_enabled(Info, startuptime),
> LogTag::_startuptime);
>
> have:
>
> TraceTime timer("Interpreter generation",
> Info, LogTag::_startuptime);
>
> or even have Info be the default so you can drop that in many cases ?
The reason I used the log_is_enabled is because the existing TraceTime
constructor requires a boolean to say whether or not do execute the
timing. As there are other options that use these functions, it made
more sense to add the optional LogTag argument to the end rather than
create a duplicate function. Example of other function call:
src/share/vm/prims/jvmtiEnv.cpp:1793: TraceTime
t("IterateOverInstancesOfClass", TraceJVMTIObjectTagging);
Plus it is more clear this way to someone reading the code that the
timer only runs when the Info level logging for startuptime is enabled.
Is that fair?
Rachel
>
> Thanks,
> David
>
>
> On 11/02/2016 7:46 AM, Rachel Protacio wrote:
>> Hello,
>>
>> 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
>> 9-internal+0-2016-02-03-174035.rprotaci.clean)
>> 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
>> 9-internal+0-2016-02-01-141226.rprotaci.8148630)
>> 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,
>> Rachel