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

[stefan.johansson at oracle.com]

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?

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