RFR: 8244817: Add configuration logging similar to ZGCs to other GCs

[Per Liden]

Hi Stefan,

On 5/19/20 9:51 AM, stefan.johansson at oracle.com wrote:
> Hi Per,
> 
> On 2020-05-18 22:30, Per Liden wrote:
>> Hi Stefan,
>>
>> On 5/18/20 7:56 PM, stefan.johansson at oracle.com wrote:
>>> Hi,
>>>
>>> Please review this enhancement to improve startup logging for G1, 
>>> Parallel and Serial.
>>>
>>> Webrev: http://cr.openjdk.java.net/~sjohanss/8244817/00/
>>> Issue: https://bugs.openjdk.java.net/browse/JDK-8244817
>>
>> Two minor suggestions:
>>
>> 1) Could we name the new class GCInitLogger?
> Sounds good, I'll change it.
> 
>>
>> 2) Could we move the "Using ..." line in universe.cpp into something 
>> like InitLogger::print_name()? Today, ZGC does a lot of logging during 
>> construction of its ZCollectedHeap, so the "Using .." line comes a bit 
>> late, and we "fix" that by printing an "Initializing ..." line early, 
>> which I wouldn't mind getting rid of. Something like this:
>>
>> diff --git a/src/hotspot/share/gc/shared/initLogger.cpp 
>> b/src/hotspot/share/gc/shared/initLogger.cpp
>> --- a/src/hotspot/share/gc/shared/initLogger.cpp
>> +++ b/src/hotspot/share/gc/shared/initLogger.cpp
>> @@ -23,6 +23,7 @@
>>    */
>>
>>   #include "precompiled.hpp"
>> +#include "gc/shared/collectedHeap.hpp"
>>   #include "gc/shared/initLogger.hpp"
>>   #include "logging/log.hpp"
>>   #include "oops/compressedOops.hpp"
>> @@ -31,6 +32,7 @@
>>   #include "utilities/globalDefinitions.hpp"
>>
>>   void InitLogger::print_all() {
>> +  print_name();
>>     print_version();
>>     print_cpu();
>>     print_memory();
>> @@ -46,6 +48,10 @@
>>     init_log.print_all();
>>   }
>>
>> +void InitLogger::print_name() {
>> +  log_info(gc)("Using %s", Universe::heap()->name());
>> +}
>> +
>>   void InitLogger::print_version() {
>>     log_info(gc, init)("Version: %s (%s)",
>>                        VM_Version::vm_release(),
>> diff --git a/src/hotspot/share/gc/shared/initLogger.hpp 
>> b/src/hotspot/share/gc/shared/initLogger.hpp
>> --- a/src/hotspot/share/gc/shared/initLogger.hpp
>> +++ b/src/hotspot/share/gc/shared/initLogger.hpp
>> @@ -30,6 +30,7 @@
>>   class InitLogger : public StackObj {
>>    protected:
>>     const char* large_pages_support();
>> +  virtual void print_name();
>>     virtual void print_version();
>>     virtual void print_cpu();
>>     virtual void print_memory();
>> diff --git a/src/hotspot/share/gc/z/zInitialize.cpp 
>> b/src/hotspot/share/gc/z/zInitialize.cpp
>> --- a/src/hotspot/share/gc/z/zInitialize.cpp
>> +++ b/src/hotspot/share/gc/z/zInitialize.cpp
>> @@ -37,7 +37,7 @@
>>   #include "runtime/vm_version.hpp"
>>
>>   ZInitialize::ZInitialize(ZBarrierSet* barrier_set) {
>> -  log_info(gc, init)("Initializing %s", ZName);
>> +  log_info(gc)("Using %s", ZName);
>>     log_info(gc, init)("Version: %s (%s)",
>>                        VM_Version::vm_release(),
>>                        VM_Version::jdk_debug_level());
>> diff --git a/src/hotspot/share/memory/universe.cpp 
>> b/src/hotspot/share/memory/universe.cpp
>> --- a/src/hotspot/share/memory/universe.cpp
>> +++ b/src/hotspot/share/memory/universe.cpp
>> @@ -721,8 +721,6 @@
>>   jint Universe::initialize_heap() {
>>     assert(_collectedHeap == NULL, "Heap already created");
>>     _collectedHeap = GCConfig::arguments()->create_heap();
>> -
>> -  log_info(gc)("Using %s", _collectedHeap->name());
>>     return _collectedHeap->initialize();
>>   }
>>
>>
>> What do you think?
> I was looking at this a bit and decided not to move the name into the 
> new logger. That log is printed with the "gc" tag only and all other 
> logging in the init-logger is "gc+init". I don't think we should move 
> the "Using %s" log to be gc+init since this is something we want shown 
> with -Xlog:gc. We could of course just say that this log is special and 
> move it in there (and still just use the gc tag) as you suggest. I'm not 
> completely against this, but I would prefer to keep it as is to print it 
> directly after the heap is created. That way the name is shown even if 
> the initialization fails. Makes sense?

Sure, it's not that important. I just thought it would have been nice to 
fix while we're in the area. But we can think about that some other time.

/Per

> 
> Cheers,
> Stefan
> 
>>
>> cheers,
>> Per
>>
>>>
>>> Summary
>>> ZGC has some really nice initialization logging that really helps 
>>> when analyzing multiple logs. It would be nice to have something 
>>> similar in the other GCs. This change adds a InitLogger which can be 
>>> used to print basic configuration that might be interesting to have 
>>> in the GC logs. ZGC have some specific things in their logs and I've 
>>> not included changing Z to make use of the new InitLogger, but this 
>>> can be done as a follow up if it makes sense.
>>>
>>> After some discussion with different people I decided to avoid adding 
>>> to the CollectedHeap interface. Instead all GCs that make use of this 
>>> should call the InitLogger in their initialization code.
>>>
>>> There might be more information that make sense to put into to this 
>>> block of logging and I plan to file a few follow-up. For example, to 
>>> look at G1s perodic GC startup logging, but also to change the the 
>>> compressed oops logging that become somewhat duplicated on info level 
>>> after this change.
>>>
>>> Testing
>>> Mach5 1-3
>>>
>>> Thanks,
>>> Stefan