8272651: G1 heap region info print order changed by JDK-8269914

Reviewed-by: tschatzl, iwalulya, ayang
This commit is contained in:
Stefan Johansson 2021-08-30 14:37:03 +00:00
parent fbffa54efe
commit f11e099a14
5 changed files with 28 additions and 20 deletions

@ -1113,8 +1113,9 @@ bool G1CollectedHeap::do_full_collection(bool explicit_gc,
const bool do_clear_all_soft_refs = clear_all_soft_refs ||
soft_ref_policy()->should_clear_all_soft_refs();
G1FullCollector collector(this, explicit_gc, do_clear_all_soft_refs, do_maximum_compaction);
G1FullGCMark gc_mark;
GCTraceTime(Info, gc) tm("Pause Full", NULL, gc_cause(), true);
G1FullCollector collector(this, explicit_gc, do_clear_all_soft_refs, do_maximum_compaction);
collector.prepare_collection();
collector.collect();
@ -3048,10 +3049,6 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
bool should_start_concurrent_mark_operation = collector_state()->in_concurrent_start_gc();
bool concurrent_operation_is_full_mark = false;
// Verification may use the gang workers, so they must be set up before.
// Individual parallel phases may override this.
set_young_collection_default_active_worker_threads();
{
// Do timing/tracing/statistics/pre- and post-logging/verification work not
// directly related to the collection. They should not be accounted for in
@ -3061,16 +3058,21 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
// determining collector state.
G1YoungGCTraceTime tm(gc_cause());
// Young GC internal pause timing
G1YoungGCNotifyPauseMark npm;
// JFR
G1YoungGCJFRTracerMark jtm(_gc_timer_stw, _gc_tracer_stw, gc_cause());
// JStat/MXBeans
G1MonitoringScope ms(monitoring_support(),
false /* full_gc */,
collector_state()->in_mixed_phase() /* all_memory_pools_affected */);
// Create the heap printer before internal pause timing to have
// heap information printed as last part of detailed GC log.
G1HeapPrinterMark hpm(this);
// Young GC internal pause timing
G1YoungGCNotifyPauseMark npm;
// Verification may use the gang workers, so they must be set up before.
// Individual parallel phases may override this.
set_young_collection_default_active_worker_threads();
// Wait for root region scan here to make sure that it is done before any
// use of the STW work gang to maximize cpu use (i.e. all cores are available

@ -31,6 +31,8 @@
#include "gc/g1/g1FullGCOopClosures.hpp"
#include "gc/g1/g1FullGCScope.hpp"
#include "gc/g1/g1RegionMarkStatsCache.hpp"
#include "gc/shared/gcId.hpp"
#include "gc/shared/gcTraceTime.hpp"
#include "gc/shared/preservedMarks.hpp"
#include "gc/shared/referenceProcessor.hpp"
#include "gc/shared/taskqueue.hpp"
@ -55,6 +57,16 @@ public:
}
};
// Full GC Mark that holds GC id and CPU time trace. Needs to be separate
// from the G1FullCollector and G1FullGCScope to allow the Full GC logging
// to have the same structure as the Young GC logging.
class G1FullGCMark : StackObj {
GCIdMark _gc_id;
GCTraceCPUTime _cpu_time;
public:
G1FullGCMark() : _gc_id(), _cpu_time() { }
};
// The G1FullCollector holds data associated with the current Full GC.
class G1FullCollector : StackObj {
G1CollectedHeap* _heap;

@ -42,12 +42,10 @@ G1FullGCScope::G1FullGCScope(G1MonitoringSupport* monitoring_support,
_rm(),
_explicit_gc(explicit_gc),
_g1h(G1CollectedHeap::heap()),
_gc_id(),
_svc_marker(SvcGCMarker::FULL),
_timer(),
_tracer(),
_active(),
_cpu_time(),
_tracer_mark(&_timer, &_tracer),
_soft_refs(clear_soft, _g1h->soft_ref_policy()),
_monitoring_scope(monitoring_support, true /* full_gc */, true /* all_memory_pools_affected */),

@ -28,8 +28,6 @@
#include "gc/g1/g1CollectedHeap.hpp"
#include "gc/g1/g1HeapTransition.hpp"
#include "gc/g1/g1Trace.hpp"
#include "gc/shared/gcId.hpp"
#include "gc/shared/gcTraceTime.hpp"
#include "gc/shared/gcTimer.hpp"
#include "gc/shared/gcVMOperations.hpp"
#include "gc/shared/isGCActiveMark.hpp"
@ -51,12 +49,10 @@ class G1FullGCScope : public StackObj {
ResourceMark _rm;
bool _explicit_gc;
G1CollectedHeap* _g1h;
GCIdMark _gc_id;
SvcGCMarker _svc_marker;
STWGCTimer _timer;
G1FullGCTracer _tracer;
IsGCActiveMark _active;
GCTraceCPUTime _cpu_time;
G1FullGCJFRTracerMark _tracer_mark;
ClearedAllSoftRefs _soft_refs;
G1MonitoringScope _monitoring_scope;

@ -73,12 +73,12 @@ public class TestEagerReclaimHumongousRegionsLog {
// This gives an array of lines containing eager reclaim of humongous regions
// log messages contents after the ":" in the following order for every GC:
// Humongous Regions: f->g
// Region Register: a.ams
// Eagerly Reclaim Humonguous Objects b.cms
// Humongous Total: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: c, Workers: 1
// Humongous Candidate: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: d, Workers: 1
// Humongous Reclaimed: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: e, Workers: 1
// Humongous Regions: f->g
String[] lines = Arrays.stream(output.getStdout().split("\\R"))
.filter(s -> (s.contains("Humongous") || s.contains("Region Register"))).map(s -> s.substring(s.indexOf(LogSeparator) + LogSeparator.length()))
@ -87,12 +87,12 @@ public class TestEagerReclaimHumongousRegionsLog {
Asserts.assertTrue(lines.length % 6 == 0, "There seems to be an unexpected amount of log messages (total: " + lines.length + ") per GC");
for (int i = 0; i < lines.length; i += 6) {
int total = Integer.parseInt(getSumValue(lines[i + 3]));
int candidate = Integer.parseInt(getSumValue(lines[i + 4]));
int reclaimed = Integer.parseInt(getSumValue(lines[i + 5]));
int total = Integer.parseInt(getSumValue(lines[i + 2]));
int candidate = Integer.parseInt(getSumValue(lines[i + 3]));
int reclaimed = Integer.parseInt(getSumValue(lines[i + 4]));
int before = Integer.parseInt(lines[i].substring(0, 1));
int after = Integer.parseInt(lines[i].substring(3, 4));
int before = Integer.parseInt(lines[i + 5].substring(0, 1));
int after = Integer.parseInt(lines[i + 5].substring(3, 4));
System.out.println("total " + total + " candidate " + candidate + " reclaimed " + reclaimed + " before " + before + " after " + after);
Asserts.assertEQ(total, candidate, "Not all humonguous objects are candidates");