- Consolidate verbose-gc output to be a single line which can be imported easily into spreadsheets.

runtime/vm/pages.cc

 // Copyright (c) 2012, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 
 #include "vm/pages.h"
 
 #include "platform/assert.h"
 #include "vm/compiler_stats.h"
 #include "vm/gc_marker.h"
 #include "vm/gc_sweeper.h"
@@ skipping 100 matching lines @@
 
 PageSpace::PageSpace(Heap* heap, intptr_t max_capacity)
     : freelist_(),
       heap_(heap),
       pages_(NULL),
       pages_tail_(NULL),
       large_pages_(NULL),
       max_capacity_(max_capacity),
       capacity_(0),
       in_use_(0),
-      count_(0),
       sweeping_(false),
       page_space_controller_(FLAG_heap_growth_space_ratio,
                              FLAG_heap_growth_rate,
                              FLAG_heap_growth_time_ratio) {
 }
 
 
 PageSpace::~PageSpace() {
   FreePages(pages_);
   FreePages(large_pages_);
@@ skipping 263 matching lines @@
     page = page->next();
   }
   page = large_pages_;
   while (page != NULL) {
     page->WriteProtect(read_only);
     page = page->next();
   }
 }
 
 
-void PageSpace::MarkSweep(bool invoke_api_callbacks, const char* gc_reason) {
+void PageSpace::MarkSweep(bool invoke_api_callbacks) {
   // MarkSweep is not reentrant. Make sure that is the case.
   ASSERT(!sweeping_);
   sweeping_ = true;
   Isolate* isolate = Isolate::Current();
   NoHandleScope no_handles(isolate);
 
   if (HeapTrace::is_enabled()) {
     isolate->heap()->trace()->TraceMarkSweepStart();
   }
 
   if (FLAG_print_free_list_before_gc) {
     OS::Print("Data Freelist (before GC):\n");
     freelist_[HeapPage::kData].Print();
     OS::Print("Executable Freelist (before GC):\n");
     freelist_[HeapPage::kExecutable].Print();
   }
 
   if (FLAG_verify_before_gc) {
     OS::PrintErr("Verifying before MarkSweep...");
     heap_->Verify();
     OS::PrintErr(" done.\n");
   }
 
-  if (FLAG_verbose_gc) {
-    OS::PrintErr("Start mark sweep for %s collection\n", gc_reason);
-  }
-  Timer timer(true, "MarkSweep");
-  timer.Start();
-  int64_t start = OS::GetCurrentTimeMillis();
+  int64_t start = OS::GetCurrentTimeMicros();
 
   // Mark all reachable old-gen objects.
   GCMarker marker(heap_);
   marker.MarkObjects(isolate, this, invoke_api_callbacks);
 
+  int64_t mid1 = OS::GetCurrentTimeMicros();
+
   // Reset the bump allocation page to unused.
   // Reset the freelists and setup sweeping.
   freelist_[HeapPage::kData].Reset();
   freelist_[HeapPage::kExecutable].Reset();
+
+  int64_t mid2 = OS::GetCurrentTimeMicros();
+
   GCSweeper sweeper(heap_);
   intptr_t in_use = 0;
 
   HeapPage* prev_page = NULL;
   HeapPage* page = pages_;
   while (page != NULL) {
     HeapPage* next_page = page->next();
     intptr_t page_in_use = sweeper.SweepPage(page, &freelist_[page->type()]);
     if (page_in_use == 0) {
       FreePage(page, prev_page);
     } else {
       in_use += page_in_use;
       prev_page = page;
     }
     // Advance to the next page.
     page = next_page;
   }
 
+  int64_t mid3 = OS::GetCurrentTimeMicros();
+
   prev_page = NULL;
   page = large_pages_;
   while (page != NULL) {
     intptr_t page_in_use = sweeper.SweepLargePage(page);
     HeapPage* next_page = page->next();
     if (page_in_use == 0) {
       FreeLargePage(page, prev_page);
     } else {
       in_use += page_in_use;
       prev_page = page;
     }
     // Advance to the next page.
     page = next_page;
   }
 
   // Record data and print if requested.
   intptr_t in_use_before = in_use_;
   in_use_ = in_use;
 
-  int64_t end = OS::GetCurrentTimeMillis();
-  timer.Stop();
+  int64_t end = OS::GetCurrentTimeMicros();
 
   // Record signals for growth control.
   page_space_controller_.EvaluateGarbageCollection(in_use_before, in_use,
                                                    start, end);
 
-  if (FLAG_verbose_gc) {
-    const intptr_t KB2 = KB / 2;
-    OS::PrintErr("Mark-Sweep[%d]: %"Pd64"us (%"Pd"K -> %"Pd"K, %"Pd"K)\n",
-                 count_,
-                 timer.TotalElapsedTime(),
-                 (in_use_before + (KB2)) / KB,
-                 (in_use + (KB2)) / KB,
-                 (capacity_ + KB2) / KB);
-  }
+  heap_->RecordTime(0, mid1 - start);
+  heap_->RecordTime(1, mid2 - mid1);
+  heap_->RecordTime(2, mid3 - mid2);
+  heap_->RecordTime(3, end - mid3);
 
   if (FLAG_print_free_list_after_gc) {
     OS::Print("Data Freelist (after GC):\n");
     freelist_[HeapPage::kData].Print();
     OS::Print("Executable Freelist (after GC):\n");
     freelist_[HeapPage::kExecutable].Print();
   }
 
   if (FLAG_verify_after_gc) {
     OS::PrintErr("Verifying after MarkSweep...");
     heap_->Verify();
     OS::PrintErr(" done.\n");
   }
 
   if (HeapTrace::is_enabled()) {
     isolate->heap()->trace()->TraceMarkSweepFinish();
   }
 
-  count_++;
   // Done, reset the marker.
   ASSERT(sweeping_);
   sweeping_ = false;
 }
 
 
 PageSpaceController::PageSpaceController(int heap_growth_ratio,
                                          int heap_growth_rate,
                                          int garbage_collection_time_ratio)
     : is_enabled_(false),
@@ skipping 33 matching lines @@
   int collected_garbage_ratio =
       static_cast<int>((static_cast<double>(in_use_before - in_use_after) /
                         static_cast<double>(in_use_before))
                        * 100.0);
   bool enough_free_space =
       (collected_garbage_ratio >= heap_growth_ratio_);
   int garbage_collection_time_fraction =
       history_.GarbageCollectionTimeFraction();
   bool enough_free_time =
       (garbage_collection_time_fraction <= garbage_collection_time_ratio_);
+
+  Heap* heap = Isolate::Current()->heap();
   if (enough_free_space && enough_free_time) {
     grow_heap_ = 0;
   } else {
-    if (FLAG_verbose_gc) {
-      OS::PrintErr("PageSpaceController: ");
-      if (!enough_free_space) {
-        OS::PrintErr("free space %d%% < %d%%",
-                     collected_garbage_ratio,
-                     heap_growth_ratio_);
-      }
-      if (!enough_free_space && !enough_free_time) {
-        OS::PrintErr(", ");
-      }
-      if (!enough_free_time) {
-        OS::PrintErr("garbage collection time %d%% > %d%%",
-                     garbage_collection_time_fraction,
-                     garbage_collection_time_ratio_);
-      }
-      OS::PrintErr("\n");
-    }
     intptr_t growth_target = static_cast<intptr_t>(in_use_after /
                                                    desired_utilization_);
     intptr_t growth_in_bytes = Utils::RoundUp(growth_target - in_use_after,
                                               PageSpace::kPageSize);
     int growth_in_pages = growth_in_bytes / PageSpace::kPageSize;
     grow_heap_ = Utils::Maximum(growth_in_pages, heap_growth_rate_);
+    heap->RecordData(2, growth_in_pages);
   }
+  heap->RecordData(0, collected_garbage_ratio);
+  heap->RecordData(1, garbage_collection_time_fraction);
+  heap->RecordData(3, grow_heap_);
 }
 
 
 PageSpaceGarbageCollectionHistory::PageSpaceGarbageCollectionHistory()
     : index_(0) {
   for (intptr_t i = 0; i < kHistoryLength; i++) {
     start_[i] = 0;
     end_[i] = 0;
   }
 }
@@ skipping 27 matching lines @@
     return 0;
   } else {
     ASSERT(total_time >= gc_time);
     int result= static_cast<int>((static_cast<double>(gc_time) /
                              static_cast<double>(total_time)) * 100);
     return result;
   }
 }
 
 }  // namespace dart