Home | History | Annotate | Download | only in collector
      1 /*
      2  * Copyright (C) 2012 The Android Open Source Project
      3  *
      4  * Licensed under the Apache License, Version 2.0 (the "License");
      5  * you may not use this file except in compliance with the License.
      6  * You may obtain a copy of the License at
      7  *
      8  *      http://www.apache.org/licenses/LICENSE-2.0
      9  *
     10  * Unless required by applicable law or agreed to in writing, software
     11  * distributed under the License is distributed on an "AS IS" BASIS,
     12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     13  * See the License for the specific language governing permissions and
     14  * limitations under the License.
     15  */
     16 
     17 #include <stdio.h>
     18 #include <unistd.h>
     19 #include <sys/mman.h>
     20 
     21 #include "garbage_collector.h"
     22 
     23 #include "android-base/stringprintf.h"
     24 
     25 #include "base/dumpable.h"
     26 #include "base/histogram-inl.h"
     27 #include "base/logging.h"  // For VLOG_IS_ON.
     28 #include "base/mutex-inl.h"
     29 #include "base/systrace.h"
     30 #include "base/time_utils.h"
     31 #include "base/utils.h"
     32 #include "gc/accounting/heap_bitmap.h"
     33 #include "gc/gc_pause_listener.h"
     34 #include "gc/heap.h"
     35 #include "gc/space/large_object_space.h"
     36 #include "gc/space/space-inl.h"
     37 #include "runtime.h"
     38 #include "thread-current-inl.h"
     39 #include "thread_list.h"
     40 
     41 namespace art {
     42 namespace gc {
     43 namespace collector {
     44 
     45 Iteration::Iteration()
     46     : duration_ns_(0), timings_("GC iteration timing logger", true, VLOG_IS_ON(heap)) {
     47   Reset(kGcCauseBackground, false);  // Reset to some place holder values.
     48 }
     49 
     50 void Iteration::Reset(GcCause gc_cause, bool clear_soft_references) {
     51   timings_.Reset();
     52   pause_times_.clear();
     53   duration_ns_ = 0;
     54   clear_soft_references_ = clear_soft_references;
     55   gc_cause_ = gc_cause;
     56   freed_ = ObjectBytePair();
     57   freed_los_ = ObjectBytePair();
     58   freed_bytes_revoke_ = 0;
     59 }
     60 
     61 uint64_t Iteration::GetEstimatedThroughput() const {
     62   // Add 1ms to prevent possible division by 0.
     63   return (static_cast<uint64_t>(freed_.bytes) * 1000) / (NsToMs(GetDurationNs()) + 1);
     64 }
     65 
     66 GarbageCollector::GarbageCollector(Heap* heap, const std::string& name)
     67     : heap_(heap),
     68       name_(name),
     69       pause_histogram_((name_ + " paused").c_str(), kPauseBucketSize, kPauseBucketCount),
     70       rss_histogram_((name_ + " peak-rss").c_str(), kMemBucketSize, kMemBucketCount),
     71       freed_bytes_histogram_((name_ + " freed-bytes").c_str(), kMemBucketSize, kMemBucketCount),
     72       cumulative_timings_(name),
     73       pause_histogram_lock_("pause histogram lock", kDefaultMutexLevel, true),
     74       is_transaction_active_(false) {
     75   ResetCumulativeStatistics();
     76 }
     77 
     78 void GarbageCollector::RegisterPause(uint64_t nano_length) {
     79   GetCurrentIteration()->pause_times_.push_back(nano_length);
     80 }
     81 
     82 void GarbageCollector::ResetCumulativeStatistics() {
     83   cumulative_timings_.Reset();
     84   total_thread_cpu_time_ns_ = 0u;
     85   total_time_ns_ = 0u;
     86   total_freed_objects_ = 0u;
     87   total_freed_bytes_ = 0;
     88   rss_histogram_.Reset();
     89   freed_bytes_histogram_.Reset();
     90   MutexLock mu(Thread::Current(), pause_histogram_lock_);
     91   pause_histogram_.Reset();
     92 }
     93 
     94 uint64_t GarbageCollector::ExtractRssFromMincore(
     95     std::list<std::pair<void*, void*>>* gc_ranges) {
     96   uint64_t rss = 0;
     97   if (gc_ranges->empty()) {
     98     return 0;
     99   }
    100   // mincore() is linux-specific syscall.
    101 #if defined(__linux__)
    102   using range_t = std::pair<void*, void*>;
    103   // Sort gc_ranges
    104   gc_ranges->sort([](const range_t& a, const range_t& b) {
    105     return std::less()(a.first, b.first);
    106   });
    107   // Merge gc_ranges. It's necessary because the kernel may merge contiguous
    108   // regions if their properties match. This is sufficient as kernel doesn't
    109   // merge those adjoining ranges which differ only in name.
    110   size_t vec_len = 0;
    111   for (auto it = gc_ranges->begin(); it != gc_ranges->end(); it++) {
    112     auto next_it = it;
    113     next_it++;
    114     while (next_it != gc_ranges->end()) {
    115       if (it->second == next_it->first) {
    116         it->second = next_it->second;
    117         next_it = gc_ranges->erase(next_it);
    118       } else {
    119         break;
    120       }
    121     }
    122     size_t length = static_cast<uint8_t*>(it->second) - static_cast<uint8_t*>(it->first);
    123     // Compute max length for vector allocation later.
    124     vec_len = std::max(vec_len, length / kPageSize);
    125   }
    126   std::unique_ptr<unsigned char[]> vec(new unsigned char[vec_len]);
    127   for (const auto it : *gc_ranges) {
    128     size_t length = static_cast<uint8_t*>(it.second) - static_cast<uint8_t*>(it.first);
    129     if (mincore(it.first, length, vec.get()) == 0) {
    130       for (size_t i = 0; i < length / kPageSize; i++) {
    131         // Least significant bit represents residency of a page. Other bits are
    132         // reserved.
    133         rss += vec[i] & 0x1;
    134       }
    135     } else {
    136       LOG(WARNING) << "Call to mincore() on memory range [0x" << std::hex << it.first
    137                    << ", 0x" << it.second << std::dec << ") failed: " << strerror(errno);
    138     }
    139   }
    140   rss *= kPageSize;
    141   rss_histogram_.AddValue(rss / KB);
    142 #endif
    143   return rss;
    144 }
    145 
    146 void GarbageCollector::Run(GcCause gc_cause, bool clear_soft_references) {
    147   ScopedTrace trace(android::base::StringPrintf("%s %s GC", PrettyCause(gc_cause), GetName()));
    148   Thread* self = Thread::Current();
    149   uint64_t start_time = NanoTime();
    150   uint64_t thread_cpu_start_time = ThreadCpuNanoTime();
    151   GetHeap()->CalculatePreGcWeightedAllocatedBytes();
    152   Iteration* current_iteration = GetCurrentIteration();
    153   current_iteration->Reset(gc_cause, clear_soft_references);
    154   // Note transaction mode is single-threaded and there's no asynchronous GC and this flag doesn't
    155   // change in the middle of a GC.
    156   is_transaction_active_ = Runtime::Current()->IsActiveTransaction();
    157   RunPhases();  // Run all the GC phases.
    158   GetHeap()->CalculatePostGcWeightedAllocatedBytes();
    159   // Add the current timings to the cumulative timings.
    160   cumulative_timings_.AddLogger(*GetTimings());
    161   // Update cumulative statistics with how many bytes the GC iteration freed.
    162   total_freed_objects_ += current_iteration->GetFreedObjects() +
    163       current_iteration->GetFreedLargeObjects();
    164   int64_t freed_bytes = current_iteration->GetFreedBytes() +
    165       current_iteration->GetFreedLargeObjectBytes();
    166   total_freed_bytes_ += freed_bytes;
    167   // Rounding negative freed bytes to 0 as we are not interested in such corner cases.
    168   freed_bytes_histogram_.AddValue(std::max<int64_t>(freed_bytes / KB, 0));
    169   uint64_t end_time = NanoTime();
    170   uint64_t thread_cpu_end_time = ThreadCpuNanoTime();
    171   total_thread_cpu_time_ns_ += thread_cpu_end_time - thread_cpu_start_time;
    172   current_iteration->SetDurationNs(end_time - start_time);
    173   if (Locks::mutator_lock_->IsExclusiveHeld(self)) {
    174     // The entire GC was paused, clear the fake pauses which might be in the pause times and add
    175     // the whole GC duration.
    176     current_iteration->pause_times_.clear();
    177     RegisterPause(current_iteration->GetDurationNs());
    178   }
    179   total_time_ns_ += current_iteration->GetDurationNs();
    180   for (uint64_t pause_time : current_iteration->GetPauseTimes()) {
    181     MutexLock mu(self, pause_histogram_lock_);
    182     pause_histogram_.AdjustAndAddValue(pause_time);
    183   }
    184   is_transaction_active_ = false;
    185 }
    186 
    187 void GarbageCollector::SwapBitmaps() {
    188   TimingLogger::ScopedTiming t(__FUNCTION__, GetTimings());
    189   // Swap the live and mark bitmaps for each alloc space. This is needed since sweep re-swaps
    190   // these bitmaps. The bitmap swapping is an optimization so that we do not need to clear the live
    191   // bits of dead objects in the live bitmap.
    192   const GcType gc_type = GetGcType();
    193   for (const auto& space : GetHeap()->GetContinuousSpaces()) {
    194     // We never allocate into zygote spaces.
    195     if (space->GetGcRetentionPolicy() == space::kGcRetentionPolicyAlwaysCollect ||
    196         (gc_type == kGcTypeFull &&
    197          space->GetGcRetentionPolicy() == space::kGcRetentionPolicyFullCollect)) {
    198       accounting::ContinuousSpaceBitmap* live_bitmap = space->GetLiveBitmap();
    199       accounting::ContinuousSpaceBitmap* mark_bitmap = space->GetMarkBitmap();
    200       if (live_bitmap != nullptr && live_bitmap != mark_bitmap) {
    201         heap_->GetLiveBitmap()->ReplaceBitmap(live_bitmap, mark_bitmap);
    202         heap_->GetMarkBitmap()->ReplaceBitmap(mark_bitmap, live_bitmap);
    203         CHECK(space->IsContinuousMemMapAllocSpace());
    204         space->AsContinuousMemMapAllocSpace()->SwapBitmaps();
    205       }
    206     }
    207   }
    208   for (const auto& disc_space : GetHeap()->GetDiscontinuousSpaces()) {
    209     space::LargeObjectSpace* space = disc_space->AsLargeObjectSpace();
    210     accounting::LargeObjectBitmap* live_set = space->GetLiveBitmap();
    211     accounting::LargeObjectBitmap* mark_set = space->GetMarkBitmap();
    212     heap_->GetLiveBitmap()->ReplaceLargeObjectBitmap(live_set, mark_set);
    213     heap_->GetMarkBitmap()->ReplaceLargeObjectBitmap(mark_set, live_set);
    214     space->SwapBitmaps();
    215   }
    216 }
    217 
    218 uint64_t GarbageCollector::GetEstimatedMeanThroughput() const {
    219   // Add 1ms to prevent possible division by 0.
    220   return (total_freed_bytes_ * 1000) / (NsToMs(GetCumulativeTimings().GetTotalNs()) + 1);
    221 }
    222 
    223 void GarbageCollector::ResetMeasurements() {
    224   {
    225     MutexLock mu(Thread::Current(), pause_histogram_lock_);
    226     pause_histogram_.Reset();
    227   }
    228   cumulative_timings_.Reset();
    229   rss_histogram_.Reset();
    230   freed_bytes_histogram_.Reset();
    231   total_thread_cpu_time_ns_ = 0u;
    232   total_time_ns_ = 0u;
    233   total_freed_objects_ = 0u;
    234   total_freed_bytes_ = 0;
    235 }
    236 
    237 GarbageCollector::ScopedPause::ScopedPause(GarbageCollector* collector, bool with_reporting)
    238     : start_time_(NanoTime()), collector_(collector), with_reporting_(with_reporting) {
    239   Runtime* runtime = Runtime::Current();
    240   runtime->GetThreadList()->SuspendAll(__FUNCTION__);
    241   if (with_reporting) {
    242     GcPauseListener* pause_listener = runtime->GetHeap()->GetGcPauseListener();
    243     if (pause_listener != nullptr) {
    244       pause_listener->StartPause();
    245     }
    246   }
    247 }
    248 
    249 GarbageCollector::ScopedPause::~ScopedPause() {
    250   collector_->RegisterPause(NanoTime() - start_time_);
    251   Runtime* runtime = Runtime::Current();
    252   if (with_reporting_) {
    253     GcPauseListener* pause_listener = runtime->GetHeap()->GetGcPauseListener();
    254     if (pause_listener != nullptr) {
    255       pause_listener->EndPause();
    256     }
    257   }
    258   runtime->GetThreadList()->ResumeAll();
    259 }
    260 
    261 // Returns the current GC iteration and assocated info.
    262 Iteration* GarbageCollector::GetCurrentIteration() {
    263   return heap_->GetCurrentGcIteration();
    264 }
    265 const Iteration* GarbageCollector::GetCurrentIteration() const {
    266   return heap_->GetCurrentGcIteration();
    267 }
    268 
    269 void GarbageCollector::RecordFree(const ObjectBytePair& freed) {
    270   GetCurrentIteration()->freed_.Add(freed);
    271   heap_->RecordFree(freed.objects, freed.bytes);
    272 }
    273 void GarbageCollector::RecordFreeLOS(const ObjectBytePair& freed) {
    274   GetCurrentIteration()->freed_los_.Add(freed);
    275   heap_->RecordFree(freed.objects, freed.bytes);
    276 }
    277 
    278 uint64_t GarbageCollector::GetTotalPausedTimeNs() {
    279   MutexLock mu(Thread::Current(), pause_histogram_lock_);
    280   return pause_histogram_.AdjustedSum();
    281 }
    282 
    283 void GarbageCollector::DumpPerformanceInfo(std::ostream& os) {
    284   const CumulativeLogger& logger = GetCumulativeTimings();
    285   const size_t iterations = logger.GetIterations();
    286   if (iterations == 0) {
    287     return;
    288   }
    289   os << Dumpable<CumulativeLogger>(logger);
    290   const uint64_t total_ns = logger.GetTotalNs();
    291   double seconds = NsToMs(logger.GetTotalNs()) / 1000.0;
    292   const uint64_t freed_bytes = GetTotalFreedBytes();
    293   const uint64_t freed_objects = GetTotalFreedObjects();
    294   {
    295     MutexLock mu(Thread::Current(), pause_histogram_lock_);
    296     if (pause_histogram_.SampleSize() > 0) {
    297       Histogram<uint64_t>::CumulativeData cumulative_data;
    298       pause_histogram_.CreateHistogram(&cumulative_data);
    299       pause_histogram_.PrintConfidenceIntervals(os, 0.99, cumulative_data);
    300     }
    301   }
    302 #if defined(__linux__)
    303   if (rss_histogram_.SampleSize() > 0) {
    304     os << rss_histogram_.Name()
    305        << ": Avg: " << PrettySize(rss_histogram_.Mean() * KB)
    306        << " Max: " << PrettySize(rss_histogram_.Max() * KB)
    307        << " Min: " << PrettySize(rss_histogram_.Min() * KB) << "\n";
    308     os << "Peak-rss Histogram: ";
    309     rss_histogram_.DumpBins(os);
    310     os << "\n";
    311   }
    312 #endif
    313   if (freed_bytes_histogram_.SampleSize() > 0) {
    314     os << freed_bytes_histogram_.Name()
    315        << ": Avg: " << PrettySize(freed_bytes_histogram_.Mean() * KB)
    316        << " Max: " << PrettySize(freed_bytes_histogram_.Max() * KB)
    317        << " Min: " << PrettySize(freed_bytes_histogram_.Min() * KB) << "\n";
    318     os << "Freed-bytes histogram: ";
    319     freed_bytes_histogram_.DumpBins(os);
    320     os << "\n";
    321   }
    322   double cpu_seconds = NsToMs(GetTotalCpuTime()) / 1000.0;
    323   os << GetName() << " total time: " << PrettyDuration(total_ns)
    324      << " mean time: " << PrettyDuration(total_ns / iterations) << "\n"
    325      << GetName() << " freed: " << freed_objects
    326      << " objects with total size " << PrettySize(freed_bytes) << "\n"
    327      << GetName() << " throughput: " << freed_objects / seconds << "/s / "
    328      << PrettySize(freed_bytes / seconds) << "/s"
    329      << "  per cpu-time: "
    330      << static_cast<uint64_t>(freed_bytes / cpu_seconds) << "/s / "
    331      << PrettySize(freed_bytes / cpu_seconds) << "/s\n";
    332 }
    333 
    334 }  // namespace collector
    335 }  // namespace gc
    336 }  // namespace art
    337