[vm, gc] Include starting concurrent marking in --verbose_gc output.
Measure sizes in MB instead of kB.
TEST=--verbose_gc
Change-Id: I5d2b45a31d2eb91665c175d8abf016329ce0f07d
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/217740
Reviewed-by: Alexander Aprelev <aam@google.com>
Commit-Queue: Ryan Macnak <rmacnak@google.com>
diff --git a/runtime/platform/globals.h b/runtime/platform/globals.h
index 7d69548..8e8c737 100644
--- a/runtime/platform/globals.h
+++ b/runtime/platform/globals.h
@@ -558,6 +558,9 @@
constexpr intptr_t RoundWordsToGB(intptr_t size_in_words) {
return (size_in_words + (GBInWords >> 1)) >> GBInWordsLog2;
}
+constexpr double WordsToMB(intptr_t size_in_words) {
+ return static_cast<double>(size_in_words) / MBInWords;
+}
constexpr intptr_t kIntptrOne = 1;
constexpr intptr_t kIntptrMin = (kIntptrOne << (kBitsPerWord - 1));
diff --git a/runtime/vm/heap/heap.cc b/runtime/vm/heap/heap.cc
index 7d4c1a4..9c8269b 100644
--- a/runtime/vm/heap/heap.cc
+++ b/runtime/vm/heap/heap.cc
@@ -409,7 +409,7 @@
if (phase == PageSpace::kAwaitingFinalization) {
CollectOldSpaceGarbage(thread, GCType::kMarkSweep, GCReason::kFinalize);
} else if (phase == PageSpace::kDone) {
- StartConcurrentMarking(thread);
+ StartConcurrentMarking(thread, GCReason::kIdle);
}
}
}
@@ -617,13 +617,23 @@
CollectNewSpaceGarbage(thread, GCReason::kFull);
}
- StartConcurrentMarking(thread);
+ StartConcurrentMarking(thread, reason);
}
}
-void Heap::StartConcurrentMarking(Thread* thread) {
+void Heap::StartConcurrentMarking(Thread* thread, GCReason reason) {
+ GcSafepointOperationScope safepoint_operation(thread);
+ RecordBeforeGC(GCType::kStartConcurrentMark, reason);
+ VMTagScope tagScope(thread, reason == GCReason::kIdle
+ ? VMTag::kGCIdleTagId
+ : VMTag::kGCOldSpaceTagId);
TIMELINE_FUNCTION_GC_DURATION(thread, "StartConcurrentMarking");
old_space_.CollectGarbage(/*compact=*/false, /*finalize=*/false);
+ RecordAfterGC(GCType::kStartConcurrentMark);
+ PrintStats();
+#if defined(SUPPORT_TIMELINE)
+ PrintStatsToTimeline(&tbes, reason);
+#endif
}
void Heap::CheckFinishConcurrentMarking(Thread* thread) {
@@ -852,6 +862,8 @@
switch (type) {
case GCType::kScavenge:
return "Scavenge";
+ case GCType::kStartConcurrentMark:
+ return "StartCMark";
case GCType::kMarkSweep:
return "MarkSweep";
case GCType::kMarkCompact:
@@ -1018,8 +1030,6 @@
stats_.before_.old_ = old_space_.GetCurrentUsage();
for (int i = 0; i < GCStats::kTimeEntries; i++)
stats_.times_[i] = 0;
- for (int i = 0; i < GCStats::kDataEntries; i++)
- stats_.data_[i] = 0;
}
static double AvgCollectionPeriod(int64_t run_time, intptr_t collections) {
@@ -1119,34 +1129,33 @@
if ((FLAG_verbose_gc_hdr != 0) &&
(((stats_.num_ - 1) % FLAG_verbose_gc_hdr) == 0)) {
OS::PrintErr(
- "[ | | | | "
+ "[ | | | | "
"| new gen | new gen | new gen "
"| old gen | old gen | old gen "
- "| sweep | safe- | roots/| stbuf/| tospc/| weaks/| ]\n"
- "[ GC isolate | space (reason) | GC# | start | time "
- "| used (kB) | capacity kB | external"
- "| used (kB) | capacity (kB) | external kB "
- "| thread| point |marking| reset | sweep |swplrge| data ]\n"
- "[ | | | (s) | (ms) "
+ "| sweep | safe- | roots/| stbuf/| tospc/| weaks/ ]\n"
+ "[ GC isolate | space (reason) | GC# | start | time "
+ "| used (MB) | capacity MB | external"
+ "| used (MB) | capacity (MB) | external MB "
+ "| thread| point |marking| reset | sweep |swplrge ]\n"
+ "[ | | | (s) | (ms) "
"|before| after|before| after| b4 |aftr"
"| before| after | before| after |before| after"
- "| (ms) | (ms) | (ms) | (ms) | (ms) | (ms) | ]\n");
+ "| (ms) | (ms) | (ms) | (ms) | (ms) | (ms) ]\n");
}
// clang-format off
OS::PrintErr(
- "[ %-13.13s, %10s(%9s), " // GC(isolate-group), type(reason)
+ "[ %-13.13s, %11s(%12s), " // GC(isolate-group), type(reason)
"%4" Pd ", " // count
"%6.2f, " // start time
"%5.1f, " // total time
- "%5" Pd ", %5" Pd ", " // new gen: in use before/after
- "%5" Pd ", %5" Pd ", " // new gen: capacity before/after
- "%3" Pd ", %3" Pd ", " // new gen: external before/after
- "%6" Pd ", %6" Pd ", " // old gen: in use before/after
- "%6" Pd ", %6" Pd ", " // old gen: capacity before/after
- "%5" Pd ", %5" Pd ", " // old gen: external before/after
+ "%5.1f, %5.1f, " // new gen: in use before/after
+ "%5.1f, %5.1f, " // new gen: capacity before/after
+ "%3.1f, %3.1f, " // new gen: external before/after
+ "%6.1f, %6.1f, " // old gen: in use before/after
+ "%6.1f, %6.1f, " // old gen: capacity before/after
+ "%5.1f, %5.1f, " // old gen: external before/after
"%6.2f, %6.2f, %6.2f, %6.2f, %6.2f, %6.2f, " // times
- "%" Pd ", %" Pd ", %" Pd ", %" Pd ", " // data
"]\n", // End with a comma to make it easier to import in spreadsheets.
isolate_group()->source()->name,
GCTypeToString(stats_.type_),
@@ -1155,28 +1164,24 @@
MicrosecondsToSeconds(isolate_group_->UptimeMicros()),
MicrosecondsToMilliseconds(stats_.after_.micros_ -
stats_.before_.micros_),
- RoundWordsToKB(stats_.before_.new_.used_in_words),
- RoundWordsToKB(stats_.after_.new_.used_in_words),
- RoundWordsToKB(stats_.before_.new_.capacity_in_words),
- RoundWordsToKB(stats_.after_.new_.capacity_in_words),
- RoundWordsToKB(stats_.before_.new_.external_in_words),
- RoundWordsToKB(stats_.after_.new_.external_in_words),
- RoundWordsToKB(stats_.before_.old_.used_in_words),
- RoundWordsToKB(stats_.after_.old_.used_in_words),
- RoundWordsToKB(stats_.before_.old_.capacity_in_words),
- RoundWordsToKB(stats_.after_.old_.capacity_in_words),
- RoundWordsToKB(stats_.before_.old_.external_in_words),
- RoundWordsToKB(stats_.after_.old_.external_in_words),
+ WordsToMB(stats_.before_.new_.used_in_words),
+ WordsToMB(stats_.after_.new_.used_in_words),
+ WordsToMB(stats_.before_.new_.capacity_in_words),
+ WordsToMB(stats_.after_.new_.capacity_in_words),
+ WordsToMB(stats_.before_.new_.external_in_words),
+ WordsToMB(stats_.after_.new_.external_in_words),
+ WordsToMB(stats_.before_.old_.used_in_words),
+ WordsToMB(stats_.after_.old_.used_in_words),
+ WordsToMB(stats_.before_.old_.capacity_in_words),
+ WordsToMB(stats_.after_.old_.capacity_in_words),
+ WordsToMB(stats_.before_.old_.external_in_words),
+ WordsToMB(stats_.after_.old_.external_in_words),
MicrosecondsToMilliseconds(stats_.times_[0]),
MicrosecondsToMilliseconds(stats_.times_[1]),
MicrosecondsToMilliseconds(stats_.times_[2]),
MicrosecondsToMilliseconds(stats_.times_[3]),
MicrosecondsToMilliseconds(stats_.times_[4]),
- MicrosecondsToMilliseconds(stats_.times_[5]),
- stats_.data_[0],
- stats_.data_[1],
- stats_.data_[2],
- stats_.data_[3]);
+ MicrosecondsToMilliseconds(stats_.times_[5]));
// clang-format on
#endif // !defined(PRODUCT)
}
diff --git a/runtime/vm/heap/heap.h b/runtime/vm/heap/heap.h
index a3973c1..04e8a62 100644
--- a/runtime/vm/heap/heap.h
+++ b/runtime/vm/heap/heap.h
@@ -126,7 +126,7 @@
void CollectAllGarbage(GCReason reason = GCReason::kFull);
void CheckStartConcurrentMarking(Thread* thread, GCReason reason);
- void StartConcurrentMarking(Thread* thread);
+ void StartConcurrentMarking(Thread* thread, GCReason reason);
void CheckFinishConcurrentMarking(Thread* thread);
void WaitForMarkerTasks(Thread* thread);
void WaitForSweeperTasks(Thread* thread);
@@ -261,11 +261,6 @@
stats_.times_[id] = micros;
}
- void RecordData(int id, intptr_t value) {
- ASSERT((id >= 0) && (id < GCStats::kDataEntries));
- stats_.data_[id] = value;
- }
-
void UpdateGlobalMaxUsed();
static bool IsAllocatableInNewSpace(intptr_t size) {
@@ -327,12 +322,10 @@
};
enum { kTimeEntries = 6 };
- enum { kDataEntries = 4 };
Data before_;
Data after_;
int64_t times_[kTimeEntries];
- intptr_t data_[kDataEntries];
private:
DISALLOW_COPY_AND_ASSIGN(GCStats);
diff --git a/runtime/vm/heap/pages.cc b/runtime/vm/heap/pages.cc
index db1541a..f17e8e6 100644
--- a/runtime/vm/heap/pages.cc
+++ b/runtime/vm/heap/pages.cc
@@ -1526,7 +1526,6 @@
ASSERT(end >= start);
history_.AddGarbageCollectionTime(start, end);
const int gc_time_fraction = history_.GarbageCollectionTimeFraction();
- heap_->RecordData(PageSpace::kGCTimeFraction, gc_time_fraction);
// Assume garbage increases linearly with allocation:
// G = kA, and estimate k from the previous cycle.
@@ -1544,7 +1543,6 @@
1.0, garbage / static_cast<double>(allocated_since_previous_gc));
const int garbage_ratio = static_cast<int>(k * 100);
- heap_->RecordData(PageSpace::kGarbageRatio, garbage_ratio);
// Define GC to be 'worthwhile' iff at least fraction t of heap is garbage.
double t = 1.0 - desired_utilization_;
@@ -1595,10 +1593,8 @@
}
}
} else {
- heap_->RecordData(PageSpace::kGarbageRatio, 100);
grow_heap = 0;
}
- heap_->RecordData(PageSpace::kPageGrowth, grow_heap);
last_usage_ = after;
intptr_t max_capacity_in_words = heap_->old_space()->max_capacity_in_words_;
@@ -1688,7 +1684,7 @@
}
#endif
- if (FLAG_log_growth) {
+ if (FLAG_log_growth || FLAG_verbose_gc) {
THR_Print("%s: threshold=%" Pd "kB, idle_threshold=%" Pd "kB, reason=%s\n",
heap_->isolate_group()->source()->name,
hard_gc_threshold_in_words_ / KBInWords,
diff --git a/runtime/vm/heap/pages.h b/runtime/vm/heap/pages.h
index 8a91944..9d039e1 100644
--- a/runtime/vm/heap/pages.h
+++ b/runtime/vm/heap/pages.h
@@ -536,11 +536,6 @@
kResetFreeLists = 3,
kSweepPages = 4,
kSweepLargePages = 5,
- // Data
- kGarbageRatio = 0,
- kGCTimeFraction = 1,
- kPageGrowth = 2,
- kAllowedGrowth = 3
};
uword TryAllocateInternal(intptr_t size,
diff --git a/runtime/vm/heap/scavenger.cc b/runtime/vm/heap/scavenger.cc
index 7cc5b8c..592627b 100644
--- a/runtime/vm/heap/scavenger.cc
+++ b/runtime/vm/heap/scavenger.cc
@@ -1148,13 +1148,10 @@
// Grab the deduplication sets out of the isolate's consolidated store buffer.
StoreBuffer* store_buffer = heap_->isolate_group()->store_buffer();
StoreBufferBlock* pending = blocks_;
- intptr_t total_count = 0;
while (pending != nullptr) {
StoreBufferBlock* next = pending->next();
// Generated code appends to store buffers; tell MemorySanitizer.
MSAN_UNPOISON(pending, sizeof(*pending));
- intptr_t count = pending->Count();
- total_count += count;
while (!pending->IsEmpty()) {
ObjectPtr raw_object = pending->Pop();
ASSERT(!raw_object->IsForwardingCorpse());
@@ -1172,10 +1169,6 @@
}
// Done iterating through old objects remembered in the store buffers.
visitor->VisitingOldObject(nullptr);
-
- heap_->RecordData(kStoreBufferEntries, total_count);
- heap_->RecordData(kDataUnused1, 0);
- heap_->RecordData(kDataUnused2, 0);
}
template <bool parallel>
diff --git a/runtime/vm/heap/scavenger.h b/runtime/vm/heap/scavenger.h
index f538f3a..ca75d9a 100644
--- a/runtime/vm/heap/scavenger.h
+++ b/runtime/vm/heap/scavenger.h
@@ -366,11 +366,6 @@
kIterateStoreBuffers = 3,
kProcessToSpace = 4,
kIterateWeaks = 5,
- // Data
- kStoreBufferEntries = 0,
- kDataUnused1 = 1,
- kDataUnused2 = 2,
- kToKBAfterStoreBuffer = 3
};
uword TryAllocateFromTLAB(Thread* thread, intptr_t size) {
diff --git a/runtime/vm/heap/spaces.h b/runtime/vm/heap/spaces.h
index 6b60e6c..f6827aa 100644
--- a/runtime/vm/heap/spaces.h
+++ b/runtime/vm/heap/spaces.h
@@ -31,6 +31,7 @@
enum class GCType {
kScavenge,
+ kStartConcurrentMark,
kMarkSweep,
kMarkCompact,
};
