# HG changeset patch
# User lkorinth
# Date 1537549038 -7200
# Node ID 5f931e3e7a63b550d832d2624db32033b875c720
# Parent d2b381ea84776debb59fac9c126b76b6955795ca
8196341: Add JFR events for parallel phases of G1
Reviewed-by: tschatzl, sangheki
diff -r d2b381ea8477 -r 5f931e3e7a63 src/hotspot/share/gc/g1/g1CollectedHeap.cpp
--- a/src/hotspot/share/gc/g1/g1CollectedHeap.cpp Tue Sep 25 18:26:46 2018 -0700
+++ b/src/hotspot/share/gc/g1/g1CollectedHeap.cpp Fri Sep 21 18:57:18 2018 +0200
@@ -3169,18 +3169,24 @@
}
bool G1ParEvacuateFollowersClosure::offer_termination() {
+ EventGCPhaseParallel event;
G1ParScanThreadState* const pss = par_scan_state();
start_term_time();
const bool res = terminator()->offer_termination();
end_term_time();
+ event.commit(GCId::current(), pss->worker_id(), G1GCPhaseTimes::phase_name(G1GCPhaseTimes::Termination));
return res;
}
void G1ParEvacuateFollowersClosure::do_void() {
+ EventGCPhaseParallel event;
G1ParScanThreadState* const pss = par_scan_state();
pss->trim_queue();
+ event.commit(GCId::current(), pss->worker_id(), G1GCPhaseTimes::phase_name(G1GCPhaseTimes::ObjCopy));
do {
+ EventGCPhaseParallel event;
pss->steal_and_trim_queue(queues());
+ event.commit(GCId::current(), pss->worker_id(), G1GCPhaseTimes::phase_name(G1GCPhaseTimes::ObjCopy));
} while (!offer_termination());
}
@@ -4050,6 +4056,7 @@
break;
}
+ EventGCPhaseParallel event;
double start_time = os::elapsedTime();
end = MIN2(end, _num_work_items);
@@ -4064,9 +4071,11 @@
if (is_young) {
young_time += time_taken;
has_young_time = true;
+ event.commit(GCId::current(), worker_id, G1GCPhaseTimes::phase_name(G1GCPhaseTimes::YoungFreeCSet));
} else {
non_young_time += time_taken;
has_non_young_time = true;
+ event.commit(GCId::current(), worker_id, G1GCPhaseTimes::phase_name(G1GCPhaseTimes::NonYoungFreeCSet));
}
start_time = end_time;
}
diff -r d2b381ea8477 -r 5f931e3e7a63 src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp
--- a/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp Tue Sep 25 18:26:46 2018 -0700
+++ b/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp Fri Sep 21 18:57:18 2018 +0200
@@ -465,6 +465,48 @@
}
}
+const char* G1GCPhaseTimes::phase_name(GCParPhases phase) {
+ static const char* names[] = {
+ "GCWorkerStart",
+ "ExtRootScan",
+ "ThreadRoots",
+ "StringTableRoots",
+ "UniverseRoots",
+ "JNIRoots",
+ "ObjectSynchronizerRoots",
+ "ManagementRoots",
+ "SystemDictionaryRoots",
+ "CLDGRoots",
+ "JVMTIRoots",
+ "CMRefRoots",
+ "WaitForStrongCLD",
+ "WeakCLDRoots",
+ "SATBFiltering",
+ "UpdateRS",
+ "ScanHCC",
+ "ScanRS",
+ "CodeRoots",
+#if INCLUDE_AOT
+ "AOTCodeRoots",
+#endif
+ "ObjCopy",
+ "Termination",
+ "Other",
+ "GCWorkerTotal",
+ "GCWorkerEnd",
+ "StringDedupQueueFixup",
+ "StringDedupTableFixup",
+ "RedirtyCards",
+ "YoungFreeCSet",
+ "NonYoungFreeCSet"
+ //GCParPhasesSentinel only used to tell end of enum
+ };
+
+ STATIC_ASSERT(ARRAY_SIZE(names) == G1GCPhaseTimes::GCParPhasesSentinel); // GCParPhases enum and corresponding string array should have the same "length", this tries to assert it
+
+ return names[phase];
+}
+
G1EvacPhaseWithTrimTimeTracker::G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time) :
_pss(pss),
_start(Ticks::now()),
@@ -490,7 +532,7 @@
}
G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id) :
- _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id) {
+ _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id), _event() {
if (_phase_times != NULL) {
_start_time = Ticks::now();
}
@@ -499,6 +541,7 @@
G1GCParPhaseTimesTracker::~G1GCParPhaseTimesTracker() {
if (_phase_times != NULL) {
_phase_times->record_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
+ _event.commit(GCId::current(), _worker_id, G1GCPhaseTimes::phase_name(_phase));
}
}
diff -r d2b381ea8477 -r 5f931e3e7a63 src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp
--- a/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp Tue Sep 25 18:26:46 2018 -0700
+++ b/src/hotspot/share/gc/g1/g1GCPhaseTimes.hpp Fri Sep 21 18:57:18 2018 +0200
@@ -27,6 +27,7 @@
#include "gc/shared/referenceProcessorPhaseTimes.hpp"
#include "gc/shared/weakProcessorPhaseTimes.hpp"
+#include "jfr/jfrEvents.hpp"
#include "logging/logLevel.hpp"
#include "memory/allocation.hpp"
#include "utilities/macros.hpp"
@@ -190,6 +191,7 @@
G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads);
void note_gc_start();
void print();
+ static const char* phase_name(GCParPhases phase);
// record the time a phase took in seconds
void record_time_secs(GCParPhases phase, uint worker_i, double secs);
@@ -385,6 +387,7 @@
G1GCPhaseTimes::GCParPhases _phase;
G1GCPhaseTimes* _phase_times;
uint _worker_id;
+ EventGCPhaseParallel _event;
public:
G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
virtual ~G1GCParPhaseTimesTracker();
diff -r d2b381ea8477 -r 5f931e3e7a63 src/hotspot/share/gc/g1/g1RemSet.cpp
--- a/src/hotspot/share/gc/g1/g1RemSet.cpp Tue Sep 25 18:26:46 2018 -0700
+++ b/src/hotspot/share/gc/g1/g1RemSet.cpp Fri Sep 21 18:57:18 2018 +0200
@@ -40,6 +40,7 @@
#include "gc/g1/heapRegionRemSet.hpp"
#include "gc/shared/gcTraceTime.inline.hpp"
#include "gc/shared/suspendibleThreadSet.hpp"
+#include "jfr/jfrEvents.hpp"
#include "memory/iterator.hpp"
#include "memory/resourceArea.hpp"
#include "oops/access.inline.hpp"
@@ -339,6 +340,7 @@
}
void G1ScanRSForRegionClosure::scan_rem_set_roots(HeapRegion* r) {
+ EventGCPhaseParallel event;
uint const region_idx = r->hrm_index();
if (_scan_state->claim_iter(region_idx)) {
@@ -392,10 +394,13 @@
scan_card(mr, region_idx_for_card);
}
+ event.commit(GCId::current(), _worker_i, G1GCPhaseTimes::phase_name(G1GCPhaseTimes::ScanRS));
}
void G1ScanRSForRegionClosure::scan_strong_code_roots(HeapRegion* r) {
+ EventGCPhaseParallel event;
r->strong_code_roots_do(_pss->closures()->weak_codeblobs());
+ event.commit(GCId::current(), _worker_i, G1GCPhaseTimes::phase_name(G1GCPhaseTimes::CodeRoots));
}
bool G1ScanRSForRegionClosure::do_heap_region(HeapRegion* r) {
diff -r d2b381ea8477 -r 5f931e3e7a63 src/hotspot/share/jfr/metadata/metadata.xml
--- a/src/hotspot/share/jfr/metadata/metadata.xml Tue Sep 25 18:26:46 2018 -0700
+++ b/src/hotspot/share/jfr/metadata/metadata.xml Fri Sep 21 18:57:18 2018 +0200
@@ -435,6 +435,13 @@
+
+
+
+
+
+
diff -r d2b381ea8477 -r 5f931e3e7a63 src/jdk.jfr/share/conf/jfr/default.jfc
--- a/src/jdk.jfr/share/conf/jfr/default.jfc Tue Sep 25 18:26:46 2018 -0700
+++ b/src/jdk.jfr/share/conf/jfr/default.jfc Fri Sep 21 18:57:18 2018 +0200
@@ -382,6 +382,11 @@
true
+
+ true
+ 0 ms
+
+
true
diff -r d2b381ea8477 -r 5f931e3e7a63 src/jdk.jfr/share/conf/jfr/profile.jfc
--- a/src/jdk.jfr/share/conf/jfr/profile.jfc Tue Sep 25 18:26:46 2018 -0700
+++ b/src/jdk.jfr/share/conf/jfr/profile.jfc Fri Sep 21 18:57:18 2018 +0200
@@ -382,6 +382,11 @@
true
+
+ true
+ 0 ms
+
+
true
diff -r d2b381ea8477 -r 5f931e3e7a63 test/jdk/TEST.groups
--- a/test/jdk/TEST.groups Tue Sep 25 18:26:46 2018 -0700
+++ b/test/jdk/TEST.groups Fri Sep 21 18:57:18 2018 +0200
@@ -504,6 +504,7 @@
jdk/jfr/event/gc/collection/TestYoungGarbageCollectionEventWithG1New.java \
jdk/jfr/event/gc/collection/TestGCEventMixedWithG1FullCollection.java \
jdk/jfr/event/gc/collection/TestGCEventMixedWithG1ConcurrentMark.java \
+ jdk/jfr/event/gc/collection/TestG1ParallelPhases.java \
jdk/jfr/event/gc/objectcount/TestObjectCountAfterGCEventWithG1FullCollection.java \
jdk/jfr/event/gc/objectcount/TestObjectCountAfterGCEventWithG1ConcurrentMark.java \
jdk/jfr/event/gc/heapsummary/TestHeapSummaryEventG1.java
diff -r d2b381ea8477 -r 5f931e3e7a63 test/jdk/jdk/jfr/event/gc/collection/TestG1ParallelPhases.java
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/test/jdk/jdk/jfr/event/gc/collection/TestG1ParallelPhases.java Fri Sep 21 18:57:18 2018 +0200
@@ -0,0 +1,183 @@
+/*
+ * Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation. Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+package jdk.jfr.event.gc.collection;
+
+import static java.lang.System.gc;
+import static java.lang.Thread.sleep;
+import static java.util.Set.of;
+import static java.util.stream.Collectors.joining;
+import static java.util.stream.Collectors.toList;
+import static java.util.stream.Collectors.toSet;
+import static java.util.stream.IntStream.range;
+import static jdk.jfr.event.gc.collection.Provoker.provokeMixedGC;
+import static jdk.test.lib.Asserts.assertEquals;
+import static jdk.test.lib.Asserts.assertTrue;
+import static jdk.test.lib.jfr.Events.fromRecording;
+import static sun.hotspot.WhiteBox.getWhiteBox;
+
+import java.io.IOException;
+import java.lang.ref.WeakReference;
+import java.math.BigDecimal;
+import java.util.ArrayList;
+import java.util.Collection;
+import java.util.List;
+import java.util.Set;
+
+import jdk.jfr.Recording;
+import jdk.test.lib.Asserts;
+import jdk.test.lib.jfr.EventNames;
+import sun.hotspot.WhiteBox;
+
+/**
+ * @test
+ * @key jfr
+ * @requires vm.hasJFR
+ * @requires vm.gc == "G1" | vm.gc == null
+ * @library /test/lib /test/jdk
+ * @build sun.hotspot.WhiteBox
+ * @run main ClassFileInstaller sun.hotspot.WhiteBox
+ * @run main/othervm -XX:+UnlockExperimentalVMOptions -XX:MaxTenuringThreshold=1 -Xms20M -Xmx20M
+ * -XX:G1MixedGCLiveThresholdPercent=100 -XX:G1HeapWastePercent=0 -XX:G1HeapRegionSize=1m
+ * -XX:+UseG1GC -XX:+UseStringDeduplication
+ * -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI
+ * jdk.jfr.event.gc.collection.TestG1ParallelPhases
+ */
+
+public class TestG1ParallelPhases {
+ public static List> weakRefs;
+
+ public static void main(String[] args) throws IOException {
+ Recording recording = new Recording();
+ recording.enable(EventNames.GCPhaseParallel);
+ recording.start();
+
+ // create more weak garbage than can fit in this heap (-Xmx20m), will force collection of weak references
+ weakRefs = range(1, 100)
+ .mapToObj(n -> new WeakReference<>(new byte[1_000_000]))
+ .collect(toList()); // force evaluation of lazy stream (all weak refs must be created)
+
+ final var MEG = 1024 * 1024;
+ provokeMixedGC(1 * MEG);
+ recording.stop();
+
+ Set usedPhases = fromRecording(recording).stream()
+ .map(e -> e.getValue("name").toString())
+ .collect(toSet());
+
+ Set allPhases = of(
+ "ExtRootScan",
+ "ThreadRoots",
+ "StringTableRoots",
+ "UniverseRoots",
+ "JNIRoots",
+ "ObjectSynchronizerRoots",
+ "ManagementRoots",
+ "SystemDictionaryRoots",
+ "CLDGRoots",
+ "JVMTIRoots",
+ "CMRefRoots",
+ "WaitForStrongCLD",
+ "WeakCLDRoots",
+ "SATBFiltering",
+ "UpdateRS",
+ "ScanHCC",
+ "ScanRS",
+ "CodeRoots",
+ "ObjCopy",
+ "Termination",
+ "StringDedupQueueFixup",
+ "StringDedupTableFixup",
+ "RedirtyCards",
+ // "PreserveCMReferents",
+ "NonYoungFreeCSet",
+ "YoungFreeCSet"
+ );
+
+ assertTrue(usedPhases.equals(allPhases), "Compare events expected and received"
+ + ", Not found phases: " + allPhases.stream().filter(p -> !usedPhases.contains(p)).collect(joining(", "))
+ + ", Not expected phases: " + usedPhases.stream().filter(p -> !allPhases.contains(p)).collect(joining(", ")));
+ }
+}
+
+/**
+ * Utility class to guarantee a mixed GC. The class allocates several arrays and
+ * promotes them to the oldgen. After that it tries to provoke mixed GC by
+ * allocating new objects.
+ */
+class Provoker {
+ private static void allocateOldObjects(
+ List liveOldObjects,
+ int g1HeapRegionSize,
+ int arraySize) {
+
+ var toUnreachable = new ArrayList();
+
+ // Allocates buffer and promotes it to the old gen. Mix live and dead old objects.
+ // allocate about two regions of old memory. At least one full old region will guarantee
+ // mixed collection in the future
+ range(0, g1HeapRegionSize/arraySize).forEach(n -> {
+ liveOldObjects.add(new byte[arraySize]);
+ toUnreachable.add(new byte[arraySize]);
+ });
+
+ // Do two young collections, MaxTenuringThreshold=1 will force promotion.
+ getWhiteBox().youngGC();
+ getWhiteBox().youngGC();
+
+ // Check it is promoted & keep alive
+ Asserts.assertTrue(getWhiteBox().isObjectInOldGen(liveOldObjects), "List of the objects is suppose to be in OldGen");
+ Asserts.assertTrue(getWhiteBox().isObjectInOldGen(toUnreachable), "List of the objects is suppose to be in OldGen");
+ }
+
+ private static void waitTillCMCFinished(int sleepTime) {
+ while (getWhiteBox().g1InConcurrentMark()) {
+ try {sleep(sleepTime);} catch (Exception e) {}
+ }
+ }
+
+ /**
+ * The necessary condition for guaranteed mixed GC is running in VM with the following flags:
+ * -XX:+UnlockExperimentalVMOptions -XX:MaxTenuringThreshold=1 -Xms{HEAP_SIZE}M
+ * -Xmx{HEAP_SIZE}M -XX:G1MixedGCLiveThresholdPercent=100 -XX:G1HeapWastePercent=0
+ * -XX:G1HeapRegionSize={REGION_SIZE}m
+ *
+ * @param provokeSize The size to allocate to provoke the start of a mixed gc (half heap size?)
+ * @param g1HeapRegionSize The size of your regions in bytes
+ */
+ public static void provokeMixedGC(int g1HeapRegionSize) {
+ final var arraySize = 20_000;
+ var liveOldObjects = new ArrayList();
+ allocateOldObjects(liveOldObjects, g1HeapRegionSize, arraySize);
+ waitTillCMCFinished(10);
+ getWhiteBox().g1StartConcMarkCycle();
+ waitTillCMCFinished(10);
+ getWhiteBox().youngGC();
+ getWhiteBox().youngGC();
+
+ // check that liveOldObjects still alive
+ assertTrue(getWhiteBox().isObjectInOldGen(liveOldObjects), "List of the objects is suppose to be in OldGen");
+ }
+}
diff -r d2b381ea8477 -r 5f931e3e7a63 test/lib/jdk/test/lib/jfr/EventNames.java
--- a/test/lib/jdk/test/lib/jfr/EventNames.java Tue Sep 25 18:26:46 2018 -0700
+++ b/test/lib/jdk/test/lib/jfr/EventNames.java Fri Sep 21 18:57:18 2018 +0200
@@ -128,6 +128,7 @@
public final static String G1EvacuationOldStatistics = PREFIX + "G1EvacuationOldStatistics";
public final static String G1BasicIHOP = PREFIX + "G1BasicIHOP";
public final static String AllocationRequiringGC = PREFIX + "AllocationRequiringGC";
+ public final static String GCPhaseParallel = PREFIX + "GCPhaseParallel";
// Compiler
public final static String Compilation = PREFIX + "Compilation";