RFR: 8152896: Convert PrintCompressedOopsMode to Unified Logging

Rachel Protacio rachel.protacio at oracle.com
Thu Apr 7 16:09:21 UTC 2016


Thank you, Harold and Stefan! Will commit.
Rachel

On 4/7/2016 11:04 AM, harold seigel wrote:
> Looks good!
>
> Thanks, Harold
>
> On 4/6/2016 3:27 PM, Rachel Protacio wrote:
>> Ok, I've gone ahead and added the 'coops' tag, making this conversion 
>> PrintCompressedOopsMode -> -Xlog:gc+heap+coops
>>
>> New webrev: http://cr.openjdk.java.net/~rprotacio/8152896.01
>>
>> Also deleted ending periods in log messages, removed 
>> "UnlockDiagnosticVMOptions" from tests where it is now unnecessary, 
>> and @require'd 64 bit in the new test.
>>
>> Thanks,
>> Rachel
>>
>> On 4/6/2016 3:09 PM, Coleen Phillimore wrote:
>>>
>>> I think adding the coops tag to isolate this logging from all the 
>>> other GC logging is a good idea.  The name "coops" to mean 
>>> "compressed oops" for the tag has meaning for us in the vm so it's 
>>> not a bad abbreviation.
>>>
>>> Coleen
>>>
>>> On 4/6/16 11:53 AM, Rachel Protacio wrote:
>>>> Hi,
>>>>
>>>> Thanks for the response. Yes, there is other gc+heap logging 
>>>> already present. As you can see from the grep below, there are a 
>>>> number of other messages, especially in the trace level (which is 
>>>> to be expected as verbose anyway). Additionally, there's the 
>>>> question of which level should be aliased to. Right now, I have it 
>>>> at the info level, which just prints the "Heap address" line but I 
>>>> could make it debug level to print the other ones from 
>>>> virtualspace.cpp.
>>>>
>>>> I'm fine with adding another tag, but I want to make sure we have a 
>>>> consensus before I do so. Does anyone else want to weigh in?
>>>>
>>>> Thanks,
>>>> Rachel
>>>>
>>>>
>>>>
>>>>    src/share/vm/runtime/arguments.cpp:1766: log_trace(gc, heap)("CMS
>>>>    ergo set MaxNewSize: " SIZE_FORMAT, MaxNewSize);
>>>>    src/share/vm/runtime/arguments.cpp:1769:    log_trace(gc, 
>>>> heap)("CMS
>>>>    set min_heap_size: " SIZE_FORMAT " initial_heap_size: " SIZE_FORMAT
>>>>    " max_heap: " SIZE_FORMAT,
>>>>    src/share/vm/runtime/arguments.cpp:1781: log_trace(gc,
>>>>    heap)("CMS ergo set NewSize: " SIZE_FORMAT, NewSize);
>>>>    src/share/vm/runtime/arguments.cpp:1788: log_trace(gc,
>>>>    heap)("CMS ergo set OldSize: " SIZE_FORMAT, OldSize);
>>>>    src/share/vm/runtime/arguments.cpp:2189: log_debug(gc,
>>>>    heap)("HeapBaseMinAddress must be at least " SIZE_FORMAT
>>>>    src/share/vm/runtime/arguments.cpp:2215:    log_trace(gc, heap)("
>>>>    Maximum heap size " SIZE_FORMAT, (size_t) reasonable_max);
>>>>    src/share/vm/runtime/arguments.cpp:2236: log_trace(gc, 
>>>> heap)("    Initial heap size " SIZE_FORMAT, 
>>>> (size_t)reasonable_initial);
>>>>    src/share/vm/runtime/arguments.cpp:2243: log_trace(gc, 
>>>> heap)("    Minimum heap size " SIZE_FORMAT, min_heap_size());
>>>>    src/share/vm/gc/shared/collectorPolicy.cpp:144: log_debug(gc,
>>>>    heap)("Minimum heap " SIZE_FORMAT "  Initial heap " SIZE_FORMAT "
>>>>    Maximum heap " SIZE_FORMAT,
>>>>    src/share/vm/gc/shared/collectorPolicy.cpp:492: log_trace(gc,
>>>>    heap)("1: Minimum young " SIZE_FORMAT "  Initial young " 
>>>> SIZE_FORMAT
>>>>    "  Maximum young " SIZE_FORMAT,
>>>>    src/share/vm/gc/shared/collectorPolicy.cpp:559: log_trace(gc,
>>>>    heap)("2: Minimum young " SIZE_FORMAT "  Initial young " 
>>>> SIZE_FORMAT
>>>>    "  Maximum young " SIZE_FORMAT,
>>>>    src/share/vm/gc/shared/collectorPolicy.cpp:576: log_trace(gc,
>>>>    heap)("Minimum old " SIZE_FORMAT "  Initial old " SIZE_FORMAT "
>>>>    Maximum old " SIZE_FORMAT,
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:102: log_trace(gc,
>>>>    heap)("Expanding %s from " SIZE_FORMAT "K by " SIZE_FORMAT "K to "
>>>>    SIZE_FORMAT "K",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:135: log_trace(gc,
>>>>    heap)("Garbage collection disabled, expanded heap instead");
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:173: log_trace(gc,
>>>>    heap)("Shrinking %s from " SIZE_FORMAT "K to " SIZE_FORMAT "K",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:210: log_trace(gc,
>>>>    heap)("TenuredGeneration::compute_new_size:");
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:211: log_trace(gc,
>>>>    heap)("    minimum_free_percentage: %6.2f maximum_used_percentage:
>>>>    %6.2f",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:214: log_trace(gc,
>>>>    heap)("     free_after_gc   : %6.1fK   used_after_gc   : %6.1fK
>>>>    capacity_after_gc   : %6.1fK",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:218: log_trace(gc,
>>>>    heap)("     free_percentage: %6.2f", free_percentage);
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:227: log_trace(gc,
>>>>    heap)("    expanding:  minimum_desired_capacity: %6.1fK
>>>>    expand_bytes: %6.1fK  _min_heap_delta_bytes: %6.1fK",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:245: log_trace(gc,
>>>>    heap)("    maximum_free_percentage: %6.2f minimum_used_percentage:
>>>>    %6.2f",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:247: log_trace(gc,
>>>>    heap)("    _capacity_at_prologue: %6.1fK minimum_desired_capacity:
>>>>    %6.1fK  maximum_desired_capacity: %6.1fK",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:273: log_trace(gc,
>>>>    heap)("    shrinking:  initSize: %.1fK maximum_desired_capacity:
>>>>    %.1fK",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:275: log_trace(gc,
>>>>    heap)("    shrink_bytes: %.1fK  current_shrink_factor: " 
>>>> SIZE_FORMAT
>>>>    "  new shrink factor: " SIZE_FORMAT " _min_heap_delta_bytes: 
>>>> %.1fK",
>>>>    src/share/vm/gc/shared/cardGeneration.cpp:292: log_trace(gc,
>>>>    heap)("    aggressive shrinking:  _capacity_at_prologue: %.1fK
>>>>    capacity_after_gc: %.1fK  expansion_for_promotion: %.1fK
>>>>    shrink_bytes: %.1fK",
>>>>    src/share/vm/gc/shared/genCollectedHeap.cpp:1134: log_info(gc,
>>>>    heap)("%s: " SIZE_FORMAT "K->" SIZE_FORMAT "K(" SIZE_FORMAT "K)",
>>>>    src/share/vm/gc/shared/genCollectedHeap.cpp:1136: log_info(gc,
>>>>    heap)("%s: " SIZE_FORMAT "K->" SIZE_FORMAT "K(" SIZE_FORMAT "K)",
>>>>    src/share/vm/gc/parallel/psOldGen.cpp:432:  log_info(gc, heap)("%s:
>>>>    "  SIZE_FORMAT "K->" SIZE_FORMAT "K("  SIZE_FORMAT "K)",
>>>>    src/share/vm/gc/parallel/psYoungGen.cpp:764: log_info(gc,
>>>>    heap)("%s: "  SIZE_FORMAT "K->" SIZE_FORMAT "K(" SIZE_FORMAT "K)",
>>>> src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp:1608: Log(gc,
>>>>    heap) log;
>>>> src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp:1893:
>>>>    log_info(gc, heap)("Old: " SIZE_FORMAT "K->" SIZE_FORMAT "K("
>>>>    SIZE_FORMAT "K)",
>>>>    src/share/vm/gc/g1/heapRegion.cpp:148:  log_info(gc, heap)("Heap
>>>>    region size: " SIZE_FORMAT "M", GrainBytes / M);
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:89:  if
>>>>    (log_is_enabled(Trace, gc, heap)) {
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:102: log_info(gc,
>>>>    heap)("Eden regions: " SIZE_FORMAT "->" SIZE_FORMAT "(" 
>>>> SIZE_FORMAT ")",
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:104: log_trace(gc, heap)("
>>>>    Used: 0K, Waste: 0K");
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:106: log_info(gc,
>>>>    heap)("Survivor regions: " SIZE_FORMAT "->" SIZE_FORMAT "("
>>>>    SIZE_FORMAT ")",
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:108: log_trace(gc, heap)("
>>>>    Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:111: log_info(gc,
>>>>    heap)("Old regions: " SIZE_FORMAT "->" SIZE_FORMAT,
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:113: log_trace(gc, heap)("
>>>>    Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:116: log_info(gc,
>>>>    heap)("Humongous regions: " SIZE_FORMAT "->" SIZE_FORMAT,
>>>>    src/share/vm/gc/g1/g1HeapTransition.cpp:118: log_trace(gc, heap)("
>>>>    Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
>>>>    src/share/vm/memory/virtualspace.cpp:83:    log_debug(gc,
>>>>    heap)("Reserved memory not at requested address: " PTR_FORMAT " 
>>>> vs "
>>>>    PTR_FORMAT, p2i(base), p2i(requested_address));
>>>>    src/share/vm/memory/virtualspace.cpp:145: log_debug(gc,
>>>>    heap)("Reserve regular memory without large pages");
>>>>    src/share/vm/memory/virtualspace.cpp:285: log_debug(gc,
>>>>    heap)("Protected page at the reserved heap base: "
>>>>    src/share/vm/memory/virtualspace.cpp:319:  log_trace(gc,
>>>>    heap)("Trying to allocate at address " PTR_FORMAT
>>>>    src/share/vm/memory/virtualspace.cpp:341: log_debug(gc,
>>>>    heap)("Reserve regular memory without large pages");
>>>>    src/share/vm/memory/virtualspace.cpp:553: log_trace(gc,
>>>>    heap)("Trying to allocate at address NULL heap of size "
>>>>    SIZE_FORMAT_HEX, size + noaccess_prefix);
>>>>    src/share/vm/memory/universe.cpp:750:    if (log_is_enabled(Info,
>>>>    gc, heap)) {
>>>>    src/share/vm/memory/universe.cpp:752:      outputStream* logst =
>>>>    Log(gc, heap)::info_stream();
>>>>    src/share/vm/memory/universe.cpp:1088:  Log(gc, heap) log;
>>>>    src/share/vm/memory/universe.cpp:1097:  Log(gc, heap) log;
>>>>
>>>>
>>>> On 4/6/2016 8:26 AM, Thomas Stüfe wrote:
>>>>> Hi Rachel,
>>>>>
>>>>> one question, does this change the output for 
>>>>> -XX:PrintCompressedOopsMode much? It seems to be wired now to 
>>>>> "LOG_TAGS(gc, heap)", which prints much more than just heap 
>>>>> reservation for the compressed oops mode. Would it be possible to 
>>>>> add a "coops" tag or similar to isolate this output?
>>>>>
>>>>> The reason I ask is that we used this flag extensively when 
>>>>> optimizing heap reservation on AIX for compressed oops, and may 
>>>>> want to continue using it or an alternative which gives the same 
>>>>> output.
>>>>>
>>>>> Kind Regards, Thomas
>>>>>
>>>>>
>>>>> On Tue, Apr 5, 2016 at 8:00 PM, Rachel Protacio 
>>>>> <rachel.protacio at oracle.com <mailto:rachel.protacio at oracle.com>> 
>>>>> wrote:
>>>>>
>>>>>     Hello,
>>>>>
>>>>>     Please review this change, converting 
>>>>> -XX:+PrintCompressedOopsMode
>>>>>     to -Xlog:gc+heap. The existing diagnostic flag has been 
>>>>> aliased to
>>>>>     the info level of this tagset (for the "Heap address" message 
>>>>> that
>>>>>     for example appears in the hs_err file), and there are both debug
>>>>>     and trace levels of logging available as well, as per our
>>>>>     established schema for assigning levels.
>>>>>
>>>>>     Bug: https://bugs.openjdk.java.net/browse/JDK-8152896
>>>>>     Open webrev: http://cr.openjdk.java.net/~rprotacio/8152896.00/
>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8152896.00/>
>>>>>
>>>>>     Passes JPRT and RBT quick/non-colo tests.
>>>>>
>>>>>     Thanks!
>>>>>     Rachel
>>>>>
>>>>>
>>>>
>>>
>>
>



More information about the hotspot-runtime-dev mailing list