Skip to content

Commit

Permalink
8272651: G1 heap region info print order changed by JDK-8269914
Browse files Browse the repository at this point in the history
Reviewed-by: tschatzl, iwalulya, ayang
  • Loading branch information
kstefanj committed Aug 30, 2021
1 parent fbffa54 commit f11e099
Show file tree
Hide file tree
Showing 5 changed files with 28 additions and 20 deletions.
18 changes: 10 additions & 8 deletions src/hotspot/share/gc/g1/g1CollectedHeap.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand Down
12 changes: 12 additions & 0 deletions src/hotspot/share/gc/g1/g1FullCollector.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -55,6 +57,16 @@ class G1FullGCSubjectToDiscoveryClosure: public BoolObjectClosure {
}
};

// 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;
Expand Down
2 changes: 0 additions & 2 deletions src/hotspot/share/gc/g1/g1FullGCScope.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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 */),
Expand Down
4 changes: 0 additions & 4 deletions src/hotspot/share/gc/g1/g1FullGCScope.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -73,12 +73,12 @@ public static void runTest() throws Exception {

// 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()))
Expand All @@ -87,12 +87,12 @@ public static void runTest() throws Exception {
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");
Expand Down

1 comment on commit f11e099

@openjdk-notifier
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please sign in to comment.