Print information about large objects freed and AllocSpace objects.
When we print information about the GC, we now print how many
AllocSpace and LOS objects were freed along with their corresponding
total sizes.
Fixed a disabled timing longer which I had accidentally done in
another CL.
Change-Id: I6cf958ec553bdbb365f242b3844461acec801078
diff --git a/runtime/gc/collector/mark_sweep.cc b/runtime/gc/collector/mark_sweep.cc
index 9c69fdf..a854971 100644
--- a/runtime/gc/collector/mark_sweep.cc
+++ b/runtime/gc/collector/mark_sweep.cc
@@ -152,16 +152,18 @@
void MarkSweep::InitializePhase() {
timings_.Reset();
base::TimingLogger::ScopedSplit split("InitializePhase", &timings_);
- mark_stack_ = GetHeap()->mark_stack_.get();
- DCHECK(mark_stack_ != NULL);
- SetImmuneRange(NULL, NULL);
- soft_reference_list_ = NULL;
- weak_reference_list_ = NULL;
- finalizer_reference_list_ = NULL;
- phantom_reference_list_ = NULL;
- cleared_reference_list_ = NULL;
+ mark_stack_ = heap_->mark_stack_.get();
+ DCHECK(mark_stack_ != nullptr);
+ SetImmuneRange(nullptr, nullptr);
+ soft_reference_list_ = nullptr;
+ weak_reference_list_ = nullptr;
+ finalizer_reference_list_ = nullptr;
+ phantom_reference_list_ = nullptr;
+ cleared_reference_list_ = nullptr;
freed_bytes_ = 0;
+ freed_large_object_bytes_ = 0;
freed_objects_ = 0;
+ freed_large_objects_ = 0;
class_count_ = 0;
array_count_ = 0;
other_count_ = 0;
@@ -173,7 +175,7 @@
work_chunks_deleted_ = 0;
reference_count_ = 0;
java_lang_Class_ = Class::GetJavaLangClass();
- CHECK(java_lang_Class_ != NULL);
+ CHECK(java_lang_Class_ != nullptr);
FindDefaultMarkBitmap();
@@ -1110,7 +1112,6 @@
}
void MarkSweep::SweepArray(accounting::ObjectStack* allocations, bool swap_bitmaps) {
- size_t freed_bytes = 0;
space::DlMallocSpace* space = heap_->GetAllocSpace();
// If we don't swap bitmaps then newly allocated Weaks go into the live bitmap but not mark
@@ -1130,6 +1131,8 @@
std::swap(large_live_objects, large_mark_objects);
}
+ size_t freed_bytes = 0;
+ size_t freed_large_object_bytes = 0;
size_t freed_objects = 0;
size_t freed_large_objects = 0;
size_t count = allocations->Size();
@@ -1150,28 +1153,28 @@
DCHECK_GE(out, objects_to_chunk_free);
DCHECK_LE(static_cast<size_t>(out - objects_to_chunk_free), kSweepArrayChunkFreeSize);
if (static_cast<size_t>(out - objects_to_chunk_free) == kSweepArrayChunkFreeSize) {
- // timings_.StartSplit("FreeList");
+ timings_.StartSplit("FreeList");
size_t chunk_freed_objects = out - objects_to_chunk_free;
freed_objects += chunk_freed_objects;
freed_bytes += space->FreeList(self, chunk_freed_objects, objects_to_chunk_free);
objects_to_chunk_free = out;
- // timings_.EndSplit();
+ timings_.EndSplit();
}
}
} else if (!large_mark_objects->Test(obj)) {
++freed_large_objects;
- freed_bytes += large_object_space->Free(self, obj);
+ freed_large_object_bytes += large_object_space->Free(self, obj);
}
}
// Free the remaining objects in chunks.
DCHECK_GE(out, objects_to_chunk_free);
DCHECK_LE(static_cast<size_t>(out - objects_to_chunk_free), kSweepArrayChunkFreeSize);
if (out - objects_to_chunk_free > 0) {
- // timings_.StartSplit("FreeList");
+ timings_.StartSplit("FreeList");
size_t chunk_freed_objects = out - objects_to_chunk_free;
freed_objects += chunk_freed_objects;
freed_bytes += space->FreeList(self, chunk_freed_objects, objects_to_chunk_free);
- // timings_.EndSplit();
+ timings_.EndSplit();
}
CHECK_EQ(count, allocations->Size());
timings_.EndSplit();
@@ -1179,9 +1182,11 @@
timings_.StartSplit("RecordFree");
VLOG(heap) << "Freed " << freed_objects << "/" << count
<< " objects with size " << PrettySize(freed_bytes);
- heap_->RecordFree(freed_objects + freed_large_objects, freed_bytes);
+ heap_->RecordFree(freed_objects + freed_large_objects, freed_bytes + freed_large_object_bytes);
freed_objects_.fetch_add(freed_objects);
+ freed_large_objects_.fetch_add(freed_large_objects);
freed_bytes_.fetch_add(freed_bytes);
+ freed_large_object_bytes_.fetch_add(freed_large_object_bytes);
timings_.EndSplit();
timings_.StartSplit("ResetStack");
@@ -1244,19 +1249,18 @@
if (swap_bitmaps) {
std::swap(large_live_objects, large_mark_objects);
}
- accounting::SpaceSetMap::Objects& live_objects = large_live_objects->GetObjects();
// O(n*log(n)) but hopefully there are not too many large objects.
size_t freed_objects = 0;
size_t freed_bytes = 0;
Thread* self = Thread::Current();
- for (const Object* obj : live_objects) {
+ for (const Object* obj : large_live_objects->GetObjects()) {
if (!large_mark_objects->Test(obj)) {
freed_bytes += large_object_space->Free(self, const_cast<Object*>(obj));
++freed_objects;
}
}
- freed_objects_.fetch_add(freed_objects);
- freed_bytes_.fetch_add(freed_bytes);
+ freed_large_objects_.fetch_add(freed_objects);
+ freed_large_object_bytes_.fetch_add(freed_bytes);
GetHeap()->RecordFree(freed_objects, freed_bytes);
}
diff --git a/runtime/gc/collector/mark_sweep.h b/runtime/gc/collector/mark_sweep.h
index ba12e64..8430839 100644
--- a/runtime/gc/collector/mark_sweep.h
+++ b/runtime/gc/collector/mark_sweep.h
@@ -170,10 +170,18 @@
return freed_bytes_;
}
+ size_t GetFreedLargeObjectBytes() const {
+ return freed_large_object_bytes_;
+ }
+
size_t GetFreedObjects() const {
return freed_objects_;
}
+ size_t GetFreedLargeObjects() const {
+ return freed_large_objects_;
+ }
+
uint64_t GetTotalTimeNs() const {
return total_time_ns_;
}
@@ -409,10 +417,14 @@
// Parallel finger.
AtomicInteger atomic_finger_;
- // Number of bytes freed in this collection.
+ // Number of non large object bytes freed in this collection.
AtomicInteger freed_bytes_;
+ // Number of large object bytes freed.
+ AtomicInteger freed_large_object_bytes_;
// Number of objects freed in this collection.
AtomicInteger freed_objects_;
+ // Number of freed large objects.
+ AtomicInteger freed_large_objects_;
// Number of classes scanned, if kCountScannedTypes.
AtomicInteger class_count_;
// Number of arrays scanned, if kCountScannedTypes.
diff --git a/runtime/gc/heap.cc b/runtime/gc/heap.cc
index e89dd66..800159a 100644
--- a/runtime/gc/heap.cc
+++ b/runtime/gc/heap.cc
@@ -1241,40 +1241,43 @@
<< "Could not find garbage collector with concurrent=" << concurrent_gc_
<< " and type=" << gc_type;
- base::TimingLogger& timings = collector->GetTimings();
-
collector->clear_soft_references_ = clear_soft_references;
collector->Run();
total_objects_freed_ever_ += collector->GetFreedObjects();
total_bytes_freed_ever_ += collector->GetFreedBytes();
+ if (care_about_pause_times_) {
+ const size_t duration = collector->GetDurationNs();
+ std::vector<uint64_t> pauses = collector->GetPauseTimes();
+ // GC for alloc pauses the allocating thread, so consider it as a pause.
+ bool was_slow = duration > kSlowGcThreshold ||
+ (gc_cause == kGcCauseForAlloc && duration > kLongGcPauseThreshold);
+ if (!was_slow) {
+ for (uint64_t pause : pauses) {
+ was_slow = was_slow || pause > kLongGcPauseThreshold;
+ }
+ }
- const size_t duration = collector->GetDurationNs();
- std::vector<uint64_t> pauses = collector->GetPauseTimes();
- bool was_slow = duration > kSlowGcThreshold ||
- (gc_cause == kGcCauseForAlloc && duration > kLongGcPauseThreshold);
- for (size_t i = 0; i < pauses.size(); ++i) {
- if (pauses[i] > kLongGcPauseThreshold) {
- was_slow = true;
- }
- }
-
- if (was_slow && care_about_pause_times_) {
- const size_t percent_free = GetPercentFree();
- const size_t current_heap_size = GetBytesAllocated();
- const size_t total_memory = GetTotalMemory();
- std::ostringstream pause_string;
- for (size_t i = 0; i < pauses.size(); ++i) {
- pause_string << PrettyDuration((pauses[i] / 1000) * 1000)
- << ((i != pauses.size() - 1) ? ", " : "");
- }
- LOG(INFO) << gc_cause << " " << collector->GetName()
- << " GC freed " << PrettySize(collector->GetFreedBytes()) << ", "
- << percent_free << "% free, " << PrettySize(current_heap_size) << "/"
- << PrettySize(total_memory) << ", " << "paused " << pause_string.str()
- << " total " << PrettyDuration((duration / 1000) * 1000);
- if (VLOG_IS_ON(heap)) {
- LOG(INFO) << Dumpable<base::TimingLogger>(timings);
- }
+ if (was_slow) {
+ const size_t percent_free = GetPercentFree();
+ const size_t current_heap_size = GetBytesAllocated();
+ const size_t total_memory = GetTotalMemory();
+ std::ostringstream pause_string;
+ for (size_t i = 0; i < pauses.size(); ++i) {
+ pause_string << PrettyDuration((pauses[i] / 1000) * 1000)
+ << ((i != pauses.size() - 1) ? ", " : "");
+ }
+ LOG(INFO) << gc_cause << " " << collector->GetName()
+ << " GC freed " << collector->GetFreedObjects() << "("
+ << PrettySize(collector->GetFreedBytes()) << ") AllocSpace objects, "
+ << collector->GetFreedLargeObjects() << "("
+ << PrettySize(collector->GetFreedLargeObjectBytes()) << ") LOS objects, "
+ << percent_free << "% free, " << PrettySize(current_heap_size) << "/"
+ << PrettySize(total_memory) << ", " << "paused " << pause_string.str()
+ << " total " << PrettyDuration((duration / 1000) * 1000);
+ if (VLOG_IS_ON(heap)) {
+ LOG(INFO) << Dumpable<base::TimingLogger>(collector->GetTimings());
+ }
+ }
}
{