Merge "Print information about large objects freed and AllocSpace objects." into dalvik-dev
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());
+        }
+    }
   }
 
   {